はじめに
ispecでは、サーバーサイドにKotlinを採用して開発を行っています。
(Kodee可愛いですよね 😊)
今回は、jarファイルで追加したライブラリが原因で、他のライブラリが動作しなくなった際の話をしようと思います。
かなりレアケースではあると思うのですが、誰かの助けになれば幸いです。
最後にまとめがあるので、お急ぎの方はどうぞ！
問題発生：ロガーが動作しなくなる
自分が担当していたプロジェクトでは、SLF4J + Logbackというよくある構成でログ出力を行っていました。
しかしある日、このログが出力されていないことに気が付きました。
アプリケーション自体は問題なく動作していますが、ログだけが出力されていません。
原因究明
原因を探っていきます。
1. エラーを読んでみる
調べていると、./gradlew run実行時に以下のエラーが表示されていました。
SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
SLF4J: Defaulting to no-operation (NOP) logger implementation
SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further
表示されていたURLにアクセスすると、以下のように書かれていました。
順番に見ていきます。
英文を翻訳したもの
この警告メッセージは、org.slf4j.impl.StaticLoggerBinderクラスをメモリにロードできなかった場合に、slf4j-apiバージョン1.7.x以前で報告されます。 これは、クラスパス上に適切なSLF4Jバインディングが見つからなかった場合に発生します。 slf4j-nop.jar、slf4j-simple.jar、slf4j-log4j12.jar、slf4j-jdk14.jar、またはlogback-classic.jarのうちの1つ（そして1つだけ）をクラス・パスに置くと問題が解決するはずです。 このメッセージが表示される場合、slf4j-apiバージョン2.0以降ではなく、slf4j-apiバージョン1.7.x以前を使用しています。 Slf4j-apiバージョン2.0.x以降では、ServiceLoaderメカニズムを使用しています。 slf4j-api 2.xをターゲットとするlogback 1.3以降のバックエンドは、org.slf4j.impl.StaticLoggerBinderと一緒に出荷されません。 slf4j-api 2.0.xをターゲットとするロギングバックエンドを配置する場合、クラスパスにslf4j-api-2.x.jarが必要です。 関連するfaqエントリも参照してください。
2. 使用しているバージョンを確認してみる
slf4j-apiバージョン1.7.x以前で報告されます
libs.versions.tomlを確認したところ、SLF4Jのバージョンはv2.0.16でした。
そもそも、このエラーの条件に該当していないように思えます🤔
3. Logbackがインストールされているか確認してみる
クラスパス上に適切なSLF4Jバインディングが見つからなかった場合に発生します
SLF4Jはファサードライブラリなので、実際にログを出力するには、それを実装したLogback等の別ライブラリが必要になります。
slf4j-nop.jar、slf4j-simple.jar、slf4j-log4j12.jar、slf4j-jdk14.jar、またはlogback-classic.jarのうちの1つ（そして1つだけ）をクラス・パスに置くと問題が解決するはずです
確認したところプロジェクトには、ちゃんとLogbackがインストールされていました。
なんで動かないんや、、😭
4. 外部サービスのライブラリを疑う
このメッセージが表示される場合、slf4j-apiバージョン2.0以降ではなく、slf4j-apiバージョン1.7.x以前を使用しています
プロジェクトではv2系を指定しているのに、なぜv1.7系が動いているのか疑問に思っていました。
その時ふと、jarファイルで追加しているライブラリが気になりました。
なぜかというと、以前も依存関係周りでそのライブラリに苦しめられたことがあったからです、、
多くの場合ライブラリは、Maven Centralなどのレジストリで配布されているものを、パッケージ名を指定してインストールすると思います。今回のプロジェクトでも、基本的にはその形でライブラリをインストールしていました。
しかし、本プロダクトが利用する外部サービスが、jarファイルでしかライブラリを配布していなかったのです。この外部サービスは、プロダクトにとってかなり重要で他のサービスに切り替えるという選択肢もありません。そのため仕方なく、jarファイルをプロジェクト内に配置して使用していました。
5. ライブラリ内でSLF4Jが使用されているか確認してみる
その外部サービスのライブラリは、すべての依存を含めたfat jarで配布されていました。
jarファイルを解凍して内包しているライブラリを確認したところ、ありました、SLF4Jが、、
そのライブラリが、SLF4Jを使用してログを出力しているコードも確認できました。
バージョンは、v1.7.36、、
おまわりさん、この人です！！🚨
6. 試しに、そのライブラリを削除してみる
このライブラリが犯人だと確定するために、ライブラリとそれに依存した処理を削除して、実行してみました。
エラーは表示されず、ログも出ている、、
早く逮捕してください！👮
7. なんで、v1.7では動かないのか
この文章にヒントがありそう
Slf4j-apiバージョン2.0.x以降では、ServiceLoaderメカニズムを使用しています。 slf4j-api 2.xをターゲットとするlogback 1.3以降のバックエンドは、org.slf4j.impl.StaticLoggerBinderと一緒に出荷されません。
ServiceLoaderとは？
ServiceLoader を端的に説明すると、Javaプログラマに通りのいい表現としては、DIのようなものです。このインタフェースを実装してるクラスの実装がほしいよ〜、というコードを書いておくと、それをCLASSPATHから探して渡してくれるんです。
SLF4Jのバージョンによる違い
- v2系以降
JavaのServiceLoaderの仕組みを使用して、実装を選択している - v2系未満
独自のStaticLoggerBinderで選択している
Logbackのバージョンによる違い
- v1.3以降
StaticLoggerBinderが同梱されていない
SLF4J v2系以降を必要とする - v1.3未満
StaticLoggerBinderが同梱されている
詳細：https://logback.qos.ch/download.html
プロジェクトの状況
なんらかの理由で、ライブラリのSLF4J v1.7.36が使用されている。
v1.7系は、StaticLoggerBinderが必要となるが、プロジェクトでインストールしているLogbackはv1.5.15で、StaticLoggerBinderが同梱されていないため、動作しないという状況のようです。
8. なぜ、ライブラリのSLF4Jが優先されているのか
そもそも、プロジェクトではv2系を指定しているのに、jarのv1.7系が参照されているのは何故か？
ChatGPTに聞いてみます。
GradleのRunタスクで使用しているクラスパスにLogbackなどのSLF4Jのバインディングが存在しないか、依存関係の解決の順序やクラスローダーの仕組みにより、jarファイルに含まれるライブラリの情報が優先されてしまい、外部で指定したLogbackが見つからなくなっている可能性があります。
読み込む順序で、優先されるものが決まる？
9. クラスパスとは？
原因究明7でも出てきたクラスパスとは？
同じくChatGPTに聞いてみます。
クラスパスとは、Java仮想マシン（JVM）が実行時にクラスやリソースを探す際の「パスの集合」のことです。実行する際、JVMはこのクラスパスに含まれるディレクトリや.jarファイル内を検索して、必要なクラスやリソースをロードします。
Javaのクラスパスでは先頭に指定されたものが優先されます。クラスパス上に同じクラスが複数存在する場合、最初に見つかったものが読み込まれます。これは-classpathオプションで指定された順序に従います。
println(System.getProperty("java.class.path"))で中身を確認できるようなので、出力してみました。すごい量のパスが表示されました。
外部サービスのライブラリが、かなり先頭にいます。
これによって、外部サービスのライブラリが優先されていたようです。
解決策
ロガーを動かすために解決策を探っていきます。
1. プロジェクト側のLogbackのバージョンを落とす？
ライブラリ側のSLF4J v1.7系が優先されてしまうのであれば、プロジェクトのLogbackをv1.3未満に落とせば、StaticLoggerBinderが同梱されているので、動くのではと思いました。
しかし、これはできませんでした。
これは我々のプロジェクト固有の問題ですが、Logback v1.3以降に依存した実装が含まれていたためです。これを修正する手もあるのですが、一旦他の方法もないか探ることにしました。
みなさんのプロジェクトであれば、このバージョンを合わせる方法で解決できると思います。
2. jarからSLF4Jだけ読み込まないようにできないか
SLF4Jは、下位互換性が担保されているようです。
では、jarライブラリ内のSLF4Jだけ除外して読み込むことはできないのでしょうか？
そうすれば、プロジェクトで指定したバージョンが使用され、動くようになりそうです。
しかし、一度解凍して、除外、再度バンドルする必要がありそうです。
これもできないことはないですが、手間がかかりそうなので、一旦他の方法もないか見てみます。
3. UnBundle版を使用してみる
配布されたライブラリの詳細を確認していると、依存がバラバラになっているUnBundle版も配布されていました。この中から、SLF4Jのjarだけ除外すれば、動作しそうな気がします。
元のfat jarを削除し、UnBundle版(slf4j.jarだけ削除)を配置して、./gradlew buildを実行したところ、ライブラリが重複しているというエラーが表示されました。
いくつかのライブラリが重複していたので、それらを除外指定してリトライします。
エラーは表示されず、問題なくログが表示されました！！🎉
まとめ
- プロジェクトで、SLF4J v2系、Logback v1.5系を使用してログ出力を行っていた
- ある日、アプリケーションの動作に問題はなかったが、ログが出力されなくなった
- 外部サービスから配布されていたjarファイル(fat jar)に含まれるSLF4Jのバージョンが古かった (v1.7.36)
- クラスパスの先頭付近にこのライブラリがおり、v1.7.36が優先的に読み込まれ使用されていた
- Logback v1.5系を使用するには、SLF4J v2系が必要であるため、ログが出力されなかった
- アプリケーション側のコードに、Logback v1.3以降二依存した実装があり、Logbackのバージョンをダウングレードすることはできなかった
- ライブラリは、依存がバラバラになったUnBundle版も配布されていたため、そこからSLF4Jのみを削除して、プロジェクト側のバージョンが使用されるようにして解決した
Discussion