3
3

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?

More than 1 year has passed since last update.

開発力強化Advent Calendar 2022

Day 16

Spring boot初心者がSpring bootのログを読むだけの記事

Posted at

はじめに

この記事はSpring boot初心者がSpring bootのログを読むだけの記事です。

環境

Java 8
Spring Framework 5.3.21
Spring boot 2.7.1

なぜログを読みたいか

  • 何もしてないのにSpringが壊れた!
  • Springが吐いたエラーメッセージで検索してみたけどヒットしない!
  • ヒットはしたけど試してみても直らないしよくわからない!
    環境構築やり直し!!!となることがありました。

ログやスタックトレースを読めれば自力でエラーを解決できる確率が上がると思います。

なぜ読めないか

  • 読み方を知らない(読もうとしない)
  • Spring bootが何をしているか知らない

一つ目に関してはそれはそう、という感じですが、読もうとしなければ読めないし、読み方を調べようとしません。

二つ目は、Spring bootが何をしているか知らないからです。Spring bootが何をしているかやんわり理解できていればログもなんとなく読めるようになります。

私の作ったよく分からない例え話を表示する
  

突然ですが、あなたの家にはカレーを作る家事ロボットが一台あり、こんなエラーを吐かれたとします。
「Error:カレーを作るのに失敗しました。ジャガイモが食べられないほどまずくなりました。」
私たちはカレーの作り方を知っている(はず)なので、「ジャガイモに火を通さな過ぎたのかな」「賞味期限が切れていたのかな」とか、カレーを作る風景を頭に浮かべ、様々な原因を推測できます。

翌日、あなたの家にあったエゾゲリンチョルバスを作る家事ロボットにこんなエラーを吐かれました。
「Error:エゾゲリンチョルバスを作れません。ブルグルが食べられないほどまずくなりました。」
なんでブルグルが変な味になってしまったのでしょう?
知らない料理(知っていたらすみません)だと作る工程も分からなければ単語も分からないので、どうしてブルグルが変な味になってしまったのか、推察する余地がありません。

こんな感じでSpring bootも、アプリ起動までに何をしているかであったり、分からない用語が多すぎるとログを読むことができません。

※エゾゲリンチョルバスはトルコ料理で、花嫁のエゾさんという方が体の悪いお義父さんのために作ったことに由来しているらしいです。

本記事のゴール

Springのログを読んだことがない初心者の方に向けて、Spring bootのログは怖くないよということを伝えることが目標です。
そのために、適当なログを見て、私が初見で分からなかったことをいくつか選んで説明します。

準備

とりあえず、本記事でログを眺めるための環境を用意します。
なんでもいいですが、Spring入門コンテンツのserving-web-contentを使用することにします。

ログを読む、といってもログに吐かれた文字をそのまま読むだけでは最初のうちは何も分からないので、ログで出力された部分のコードを読んでいきます。
そのために以下を用意しておきます。

  • IDE(デバッグ用)
  • Spring公式Github
  • ドキュメント(必要に応じて)

ログの付近のコードを追う

ログ前後のコードを読むときに、最初に思いつく方法は、ログに含まれる文字列で検索することです。
しかし、普通の.javaのファイルと違ってSpringのコード等、外部プロジェクトはGradle等で通常jar化されたものが落ちてくるのでEclipse等で検索できません。(もしかしたらできるのかもしれませんが)
ですが有り難いことに、SpringのコードはGithubで公開されています。

Githubの検索は最近正規表現がサポートされたようなのですが、個人的には検索が苦手なのでできればエディタで開きたいです。
でも、クローンするのは面倒くさいので以下のサービスを使ったりしています。

以下は"Creating shared instance"のログの場所を検索する例です。
image.png
springframework.beans.factory.support.DefaultSingletonBeanRegistry.java が引っかかりました。
後はこれをブラウザで読むでもいいですし、動かしながら見たい場合は同じファイルをIDEで開いてデバッグポイントを設定します。
ステップ実行をしたり呼び出し元を調べたりすることで、そのログがどのような流れで出力されたのかが分かるようになります。

image.png

これで最低限コードを追いかけながらログを読む準備ができました。
(正直これは苦肉の策で編み出した方法なので、もっと良い方法がありそうです。もしあれば教えていただけると幸いです。。)

ログを出してみる

1行目でアプリケーションを開始しているぞ、と言っています。
5行目でWebサーバー(Tomcat)が初期化されたようです。
9行目でServletWebServerApplicationContext が初期化されたようですね。

ところでc.e.s.ServingWebContentApplicationみたいなc.e.sってなんでしょう?
後、ApplicationContextがよく分かりません。

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::                (v2.7.1)

// ↓ここから1行目
2022-12-16 12:29:03.744  INFO 27520 --- [  restartedMain] c.e.s.ServingWebContentApplication       : Starting ServingWebContentApplication using Java 1.8.0_332 on desktop_xxxx with PID 27520 (C:\Users\xxx\Documents\spring_start\gs-serving-web-content-complete\bin\main started by xxx in C:\Users\xxx\Documents\spring_start\gs-serving-web-content-complete) // ★
2022-12-16 12:29:03.745  INFO 27520 --- [  restartedMain] c.e.s.ServingWebContentApplication       : No active profile set, falling back to 1 default profile: "default"
2022-12-16 12:29:03.781  INFO 27520 --- [  restartedMain] .e.DevToolsPropertyDefaultsPostProcessor : Devtools property defaults active! Set 'spring.devtools.add-properties' to 'false' to disable
2022-12-16 12:29:03.781  INFO 27520 --- [  restartedMain] .e.DevToolsPropertyDefaultsPostProcessor : For additional web related logging consider setting the 'logging.level.web' property to 'DEBUG'
2022-12-16 12:29:04.454  INFO 27520 --- [  restartedMain] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http) // ★
2022-12-16 12:29:04.465  INFO 27520 --- [  restartedMain] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2022-12-16 12:29:04.465  INFO 27520 --- [  restartedMain] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.64]
2022-12-16 12:29:04.514  INFO 27520 --- [  restartedMain] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2022-12-16 12:29:04.514  INFO 27520 --- [  restartedMain] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 733 ms // ★
2022-12-16 12:29:04.669  INFO 27520 --- [  restartedMain] o.s.b.a.w.s.WelcomePageHandlerMapping    : Adding welcome page: class path resource [static/index.html]
2022-12-16 12:29:04.774  INFO 27520 --- [  restartedMain] o.s.b.d.a.OptionalLiveReloadServer       : LiveReload server is running on port 35729
2022-12-16 12:29:04.800  INFO 27520 --- [  restartedMain] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2022-12-16 12:29:04.808  INFO 27520 --- [  restartedMain] c.e.s.ServingWebContentApplication       : Started ServingWebContentApplication in 1.316 seconds (JVM running for 2.026)

ログの形式

一つ目の疑問が生まれたのはログの形式を知っていないからです。

Spring bootのログですが、左から

  1. 日時
  2. ログレベル
  3. プロセスID
    --- (セパレータ)
  4. スレッド名
  5. ロガー名
  6. ログメッセージ

を表します。例えば下記だと、

2022-12-11 16:47:18.717 DEBUG 15276 --- [  restartedMain] o.s.boot.SpringApplication               : Loading source class com.example.servingwebcontent.ServingWebContentApplication
  1. 2022-12-11 16:47:18に
  2. DEBUGレベルのログが出力され、
  3. WebサーバーのプロセスIDが15276で、
  4. restartedMainのスレッドで、(devtools使用のため)
  5. org.springframework.bootのSpringApplicatrion.javaというロガー名で
  6. ServingWebContentApplicationをロードしています。

という意味になります。

WebAplicationContextとは

Web アプリケーションの構成を提供するインターフェースです。
実体は、DIコンテナ(beanを管理する基盤)です。
これにDI(依存性注入)したいクラスを管理させ、必要なときに以下のようなイメージでインスタンスを取り出すということをSpring bootの中でたくさんやっています。

SampleGetBean.java
ApplicationContext context = ...;
HogeHoge hogeHoge = context.getBean(HogeHoge.class);

  • DIコンテナの参考記事

WebApplicationContextの初期化で何をしているか確認してみます。
ログが出力された箇所は、org.springframework.boot.web.servlet.contextパッケージのServletWebServerAplicationContextクラスで行われています。

ServletWebServerAplicationContext.java
protected void prepareWebApplicationContext(ServletContext servletContext) {
    try {
        ...
        setServletContext(servletContext);
        if (logger.isInfoEnabled()) {
            long elapsedTime = System.currentTimeMillis() - getStartupDate();
            logger.info("Root WebApplicationContext: initialization completed in " + elapsedTime + " ms");
        }
    }
    catch (RuntimeException | Error ex) {
        ...
    }   
}

WebApplicationContextの初期化が完了したログの直前で、servletContextをApplicationContextにセットしていることが分かります。
ServletContextは、JavaEEのインターフェースで、サーブレットがサーブレットコンテナと通信するために使用する一連のメソッドを定義したインターフェースのようです。
Springがサーブレットを使ってなんやかんややるためにDIコンテナに登録している感じだと思います。

少なくとも、元をたどるとcreateWebServerから呼び出されているので、Webサーバーを起動する準備の一つだということ分かります。

ServletWebSerberApplicationContext.java
protected void onRefresh() {
		super.onRefresh();
		try {
			createWebServer(); //←ここ
		}
		catch (Throwable ex) {
			throw new ApplicationContextException("Unable to start web server", ex);
		}
	}

ログレベルの変更

ところで、先ほど表示したログは件数が少なかったですね。
Spring bootのログレベルはERRORWARNINFODEBUGTRACEの5種類があります。
これを変える一番簡単な方法は
application.propertiesを変えることです。例えば、ルートのログレベルをDEBUGに変更したい場合は以下のようにします。

application.properties
logging.level.root=DEBUG

DEBUGレベルでログを見てみる

先程実行したアプリケーションの設定を変えて、DEBUGレベルでログを出力させてみました。
先ほどと比べるとずいぶん長いです。
省略していますが、Creating shared instance of singleton beanの記述がいくつもあって気になりますね。
また、CONDITIONS EVALUATION REPORTの下にPositive matches:とかNegative matches:とか書いてあるのがよく分かりません。

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::                (v2.7.1)

2022-12-11 16:47:18.716  INFO 15276 --- [  restartedMain] c.e.s.ServingWebContentApplication       : Starting ServingWebContentApplication using Java 1.8.0_332 on desktop_xxx with PID 15276 (C:\Users\xxx\Documents\spring_start\gs-serving-web-content-complete\bin\main started by xxx in C:\Users\xxx\Documents\spring_start\gs-serving-web-content-complete)
2022-12-11 16:47:18.716 DEBUG 15276 --- [  restartedMain] c.e.s.ServingWebContentApplication       : Running with Spring Boot v2.7.1, Spring v5.3.21
2022-12-11 16:47:18.717  INFO 15276 --- [  restartedMain] c.e.s.ServingWebContentApplication       : No active profile set, falling back to 1 default profile: "default"
2022-12-11 16:47:18.717 DEBUG 15276 --- [  restartedMain] o.s.boot.SpringApplication               : Loading source class com.example.servingwebcontent.ServingWebContentApplication
2022-12-11 16:47:18.739 DEBUG 15276 --- [  restartedMain] o.s.b.devtools.restart.ChangeableUrls    : Matching URLs for reloading : [file:/C:/Users/xxx/Documents/spring_start/gs-serving-web-content-complete/bin/main/]
2022-12-11 16:47:18.739 DEBUG 15276 --- [  restartedMain] o.s.b.d.settings.DevToolsSettings        : Included patterns for restart : []
2022-12-11 16:47:18.739 DEBUG 15276 --- [  restartedMain] o.s.b.d.settings.DevToolsSettings        : Excluded patterns for restart : [/spring-boot-actuator/(bin|build|out)/, /spring-boot-devtools/(bin|build|out)/, /spring-boot/(bin|build|out)/, /spring-boot-starter-[\w-]+/, /spring-boot-autoconfigure/(bin|build|out)/, /spring-boot-starter/(bin|build|out)/]
2022-12-11 16:47:18.739  INFO 15276 --- [  restartedMain] .e.DevToolsPropertyDefaultsPostProcessor : Devtools property defaults active! Set 'spring.devtools.add-properties' to 'false' to disable
2022-12-11 16:47:18.739  INFO 15276 --- [  restartedMain] .e.DevToolsPropertyDefaultsPostProcessor : For additional web related logging consider setting the 'logging.level.web' property to 'DEBUG'
2022-12-11 16:47:18.740 DEBUG 15276 --- [  restartedMain] ConfigServletWebServerApplicationContext : Refreshing org.springframework.boot.web.servlet.context.AnnotationConfigServletWebServerApplicationContext@4bdc50a1
2022-12-11 16:47:18.750 DEBUG 15276 --- [  restartedMain] o.s.b.f.s.DefaultListableBeanFactory     : Creating shared instance of singleton bean 'org.springframework.context.annotation.internalConfigurationAnnotationProcessor'
2022-12-11 16:47:18.757 DEBUG 15276 --- [  restartedMain] o.s.b.f.s.DefaultListableBeanFactory     : Creating shared instance of singleton bean 'org.springframework.boot.autoconfigure.internalCachingMetadataReaderFactory' 
2022-12-11 16:47:18.760 DEBUG 15276 --- [  restartedMain] o.s.b.f.s.DefaultListableBeanFactory     : Creating shared instance of singleton bean 'propertySourcesPlaceholderConfigurer'
2022-12-11 16:47:18.760 DEBUG 15276 --- [  restartedMain] o.s.b.f.s.DefaultListableBeanFactory     : Creating shared instance of singleton bean 'org.springframework.boot.sql.init.dependency.DatabaseInitializationDependencyConfigurer$DependsOnDatabaseInitializationPostProcessor'
2022-12-11 16:47:18.763 DEBUG 15276 --- [  restartedMain] o.s.b.f.s.DefaultListableBeanFactory     : Creating shared instance of singleton bean 'org.springframework.context.event.internalEventListenerProcessor'
2022-12-11 16:47:18.763 DEBUG 15276 --- [  restartedMain] o.s.b.f.s.DefaultListableBeanFactory     : Creating shared instance of singleton bean 'preserveErrorControllerTargetClassPostProcessor'
2022-12-11 16:47:18.768 DEBUG 15276 --- [  restartedMain] o.s.b.f.s.DefaultListableBeanFactory     : Creating shared instance of singleton bean 'forceAutoProxyCreatorToUseClassProxying'
2022-12-11 16:47:18.771 DEBUG 15276 --- [  restartedMain] o.s.b.f.s.DefaultListableBeanFactory     : Creating shared instance of singleton bean 'org.springframework.context.event.internalEventListenerFactory'
2022-12-11 16:47:18.771 DEBUG 15276 --- [  restartedMain] o.s.b.f.s.DefaultListableBeanFactory     : Creating shared instance of singleton bean 'org.springframework.context.annotation.internalAutowiredAnnotationProcessor'
...(省略)

============================
CONDITIONS EVALUATION REPORT
============================


Positive matches:
-----------------

   AopAutoConfiguration matched:
      - @ConditionalOnProperty (spring.aop.auto=true) matched (OnPropertyCondition)

   AopAutoConfiguration.ClassProxyingConfiguration matched:
      - @ConditionalOnMissingClass did not find unwanted class 'org.aspectj.weaver.Advice' (OnClassCondition)
      - @ConditionalOnProperty (spring.aop.proxy-target-class=true) matched (OnPropertyCondition)

...(省略)


Negative matches:
-----------------

   ActiveMQAutoConfiguration:
      Did not match:
         - @ConditionalOnClass did not find required class 'javax.jms.ConnectionFactory' (OnClassCondition)

   AopAutoConfiguration.AspectJAutoProxyingConfiguration:
      Did not match:
         - @ConditionalOnClass did not find required class 'org.aspectj.weaver.Advice' (OnClassCondition)

...(省略)


Exclusions:
-----------

    None


Unconditional classes:
----------------------

    org.springframework.boot.autoconfigure.context.ConfigurationPropertiesAutoConfiguration

    org.springframework.boot.autoconfigure.context.LifecycleAutoConfiguration

...(省略)


2022-12-11 16:47:19.432  INFO 15276 --- [  restartedMain] c.e.s.ServingWebContentApplication       : Started ServingWebContentApplication in 0.887 seconds (JVM running for 1.294)
2022-12-11 16:47:19.432 DEBUG 15276 --- [  restartedMain] o.s.b.a.ApplicationAvailabilityBean      : Application availability state LivenessState changed to CORRECT
2022-12-11 16:47:19.433 DEBUG 15276 --- [  restartedMain] o.s.boot.devtools.restart.Restarter      : Creating new Restarter for thread Thread[main,5,main]
2022-12-11 16:47:19.433 DEBUG 15276 --- [  restartedMain] o.s.boot.devtools.restart.Restarter      : Immediately restarting application
2022-12-11 16:47:19.433 DEBUG 15276 --- [  restartedMain] o.s.boot.devtools.restart.Restarter      : Starting application com.example.servingwebcontent.ServingWebContentApplication with URLs [file:/C:/Users/xxx/Documents/spring_start/gs-serving-web-content-complete/bin/main/]
2022-12-11 16:47:19.433 DEBUG 15276 --- [  restartedMain] o.s.b.a.ApplicationAvailabilityBean      : Application availability state ReadinessState changed to ACCEPTING_TRAFFIC
2022-12-11 16:47:19.654 DEBUG 15276 --- [on(2)-127.0.0.1] sun.rmi.transport.tcp                    : RMI TCP Connection(2)-127.0.0.1: (port 63303) op = 82
2022-12-11 16:47:19.656 DEBUG 15276 --- [on(2)-127.0.0.1] sun.rmi.transport.tcp                    : RMI TCP Connection(2)-127.0.0.1: (port 63303) op = 80
2022-12-11 16:47:19.657 DEBUG 15276 --- [on(2)-127.0.0.1] sun.rmi.loader                           : RMI TCP Connection(2)-127.0.0.1: name = "javax.management.ObjectName", codebase = ""

AutoConfiguratinについて

これらの疑問については、AutoConfigurationあたりを抑えておけばだいたい解決します。
Creating shared instance of ~は、インスタンス作ったよーという意味ですが、AutoConfigurationはSpring bootが勝手にインスタンスを作ってくれる機能だからです。
AutoConfigrationについては以下の記事が分かりやすかったです。

mainメソッドが記述されているクラスに@SpringBootApplicationを付けることで、Autoconfigurationされるクラスが選択されます。

これらの仕組みも上記記事を見れば分かるので説明を割愛しますが、

クラスパス上の/META-INF/spring.factoriesよりインポート対象のコンフィギュレーションクラスを取得するようになっており、以下のコンフィギュレーションクラスがインポート対象になっています。

こちらの記述は、リポジトリで確認したところ、2022年2月のMergeでfactoryとConfigurationクラスの記載ファイルが分離され、ConfigurationクラスはMETA-INF/spring-autoconfigure-metadata.propertiesに記述されるようになったようです。(2022年12月現在)

これまでと同じく、ログを吐かれた前後の処理も見ておきます。
ログが吐かれた部分はDefaultSingletonBeanRegistry.javaのgetSingletonメソッドの中にあります。
やっていることは単純で、引数で渡されたbeanNameという名前のbeanが作成済みかどうかチェックし、なければ作成をしています。

DefaultSingletonBeanRegistry.java
public Object getSingleton(String beanName, ObjectFactory<?> singletonFactory) {
		Assert.notNull(beanName, "Bean name must not be null");
		synchronized (this.singletonObjects) {
			Object singletonObject = this.singletonObjects.get(beanName); // 既に作成済でないかチェック
			if (singletonObject == null) {
				...
				if (logger.isDebugEnabled()) {
					logger.debug("Creating shared instance of singleton bean '" + beanName + "'");
				}
				...
				try {
					singletonObject = singletonFactory.getObject(); // 作成
					newSingleton = true;
				}
				catch (IllegalStateException ex) {
                    ...
				}
				if (newSingleton) {
					addSingleton(beanName, singletonObject);
				}
			}
			return singletonObject; //作ったものを返却
		}
	}

CONDITIONS EVALUATION REPORTについて

最後に、CONDITIONS EVALUATION REPORTについてですが、これもAutoConfigurationに関係します。
そういえば、先ほどConfigurationクラスは`META-INF/spring-autoconfigure-metadata.propertiesに記述されているとお伝えしましたが、中身がどうなっているか見ていませんでした。見てみましょう。

org.springframework.boot.autoconfigure.AutoConfiguration.imports
org.springframework.boot.autoconfigure.admin.SpringApplicationAdminJmxAutoConfiguration
org.springframework.boot.autoconfigure.aop.AopAutoConfiguration
org.springframework.boot.autoconfigure.amqp.RabbitAutoConfiguration
org.springframework.boot.autoconfigure.batch.BatchAutoConfiguration
...

そういえば、さっきのログですが、Positive matchesの一番上に以下の記述がありました。

   AopAutoConfiguration matched:
      - @ConditionalOnProperty (spring.aop.auto=true) matched (OnPropertyCondition)

どちらにもAopAutoConfigurationが登場していますね。CONDITIONS EVALUATION REPORTの内容とAutoConfigurationは関係がありそうです。
AopAutoConfiguration.javaを見てみます。

org.springframework.boot.autoconfigure.aop.AopAutoConfiguration.java
@AutoConfiguration
@ConditionalOnProperty(prefix = "spring.aop", name = "auto", havingValue = "true", matchIfMissing = true)
public class AopAutoConfiguration {
    ...
}

@ConditionalOnProperty というのが気になります。これは、特定の条件下でのみBean定義を行うことを示すConditionalアノテーションのうちの一つです。

実は、この@ConditionalOnProperty が先のCONDITIONS EVALUATION REPORTに関係しています。
CONDITIONS EVALUATION REPORTとは、条件付きのConfigurationがどのような判定をされたかの結果です。

Conditionalアノテーションには様々な種類がありますが、@ConditionalOnPropertyの場合は、application.propertiesなど、プロパティファイルやシステムプロパティに指定したアノテーションがある場合実行されるものです。
つまり、先ほどのログでAopAutoConfigurationがPositive Matchのところに出力されたのはこの条件に合致したということです。

試しに、application.propertiesで以下の設定をして再実行すると、Positive MatchからNegative Matchに変更されました。

application.properties
spring.aop.auto=false
Negative matches:
-----------------

   ActiveMQAutoConfiguration:
      Did not match:
         - @ConditionalOnClass did not find required class 'javax.jms.ConnectionFactory' (OnClassCondition)

次に、Exclusions以下に出力されたものですが、これは開発者が意図的に無効にしたAutoConfigurationクラスを表します。
試しにAopAutoConfigurationを無効にしてみます。
これをするにはmainメソッドのクラスにのSpringBootApplidcationアノテーションにexcludeの指定をします。

ServingWebContentApplication.java
@SpringBootApplication(exclude = { AopAutoConfiguration.class })
public class ServingWebContentApplication {

    public static void main(String[] args) {
        SpringApplication.run(ServingWebContentApplication.class, args);
    }

}

再度実行すると、AopAutoConfigurationがExclusionsの部分に出力されるようになりました。

Exclusions:
-----------

    org.springframework.boot.autoconfigure.aop.AopAutoConfiguration

最後のUnconditional classesは、Condition Evaluationレポートの評価対象ではあったものの、Conditionalアノテーションがなかったクラスです。
ちなみにですが、これらのログ出力はorg.springframework.boot.autoconfigure.loggingフォルダのContitionalEvaluationReportMessage.javaで行われています。

ContitionalEvaluationReportMessage.java
// PositiveMatchesをログ出力している部分
private void logPositiveMatches(StringBuilder message, Map<String, ConditionAndOutcomes> shortOutcomes) {
		message.append(String.format("Positive matches:%n"));
		message.append(String.format("-----------------%n"));
		List<Entry<String, ConditionAndOutcomes>> matched = shortOutcomes.entrySet().stream()
				.filter((entry) -> entry.getValue().isFullMatch()).toList();
		if (matched.isEmpty()) {
			message.append(String.format("%n    None%n"));
		}
		else {
			matched.forEach((entry) -> addMatchLogMessage(message, entry.getKey(), entry.getValue()));
		}
		message.append(String.format("%n%n"));
	}

まとめ

Spring bootのログを読んでみました。
すごくざっくりで怒られそうですが、Spring bootアプリケーションが実行されるとWebサーバーの起動をして、Beanをたくさん生成してDIコンテナに注入するということをしていることが分かりました。
上記の内容だけでも知っておけばSpring bootのログ耐性がちょっとはつくかな?と思いますし、起動に失敗しても「分からない単語を調べる」/「コード読む」をやれば以外とログを読めなくはないんだな、ということが少しでも伝われば幸いです。

3
3
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
3
3

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?