上一篇文章,我们紧紧围绕 @SpringBootApplication 引入的注解和类,对 Spring Boot 项目的启动过程做了一次分析。在实际的开发过程中,项目的代码毫无疑问是与我们最为相关的,另外,我们也不可忽视项目日志在我们日常开发中所起的作用。因此,本文将围绕项目的启动日志,对项目的启动过程再做一次分析,以便于我们更好地理解项目的运行逻辑。本系列文章,笔者将会使用较多的笔墨展示代码与日志的相互关联,希望通过这样的方式,可以慢慢让读者培养起一种代码与日志彼此贯穿的思路,以帮助读者在实际开发过程中,更好地解决所遇到的问题。

下面是项目的一次启动日志:


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

2022-09-08 08:28:22.964  INFO 54995 --- [           main] o.s.springweb.HelloWorldApplication      : Starting HelloWorldApplication using Java 11.0.12 on susamludeMac.local with PID 54995 (/Users/susamlu/code/java/spring-web/spring-web-helloworld/target/classes started by susamlu in /Users/susamlu/code/java/spring-web)
2022-09-08 08:28:22.968  INFO 54995 --- [           main] o.s.springweb.HelloWorldApplication      : No active profile set, falling back to 1 default profile: "default"
2022-09-08 08:28:24.900  INFO 54995 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2022-09-08 08:28:24.912  INFO 54995 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2022-09-08 08:28:24.913  INFO 54995 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.65]
2022-09-08 08:28:25.090  INFO 54995 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2022-09-08 08:28:25.091  INFO 54995 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 1910 ms
2022-09-08 08:28:25.857  INFO 54995 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2022-09-08 08:28:25.873  INFO 54995 --- [           main] o.s.springweb.HelloWorldApplication      : Started HelloWorldApplication in 3.735 seconds (JVM running for 4.41)

SpringApplication 的静态 run() 方法,最终会调用到自身的实例 run() 方法。实例 run() 方法的内容会相对比较复杂,为了简化其中的逻辑,我们重点关注 printBanner()、prepareContext()、refreshContext() 几个方法。

public class SpringApplication {

    // ...

    public ConfigurableApplicationContext run(String... args) {
        // ...
        Banner printedBanner = printBanner(environment);
        // ...
        prepareContext(bootstrapContext, context, environment, listeners, applicationArguments, printedBanner);
        refreshContext(context);
        // ...
    }

    // ...

}

printBanner

printBanner() 见名知意,是用来打印 Spring Boot 项目的 Banner 的:


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

SpringApplication 调用 SpringApplicationBannerPrinter 的 print() 方法打印 Banner。

public class SpringApplication {

    // ...

    private Banner printBanner(ConfigurableEnvironment environment) {
        // ...
        SpringApplicationBannerPrinter bannerPrinter = new SpringApplicationBannerPrinter(resourceLoader, this.banner);
        // ...
        return bannerPrinter.print(environment, this.mainApplicationClass, System.out);
    }

    // ...

}

SpringApplicationBannerPrinter 优先打印 ImageBanner 或 TextBanner,如果没有设置 ImageBanner 和 TextBanner,则打印 Spring Boot 默认的 Banner。

class SpringApplicationBannerPrinter {

    // ...

    // TextBanner 的文件名
    static final String DEFAULT_BANNER_LOCATION = "banner.txt";

    // ImageBanner 支持的后缀格式
    static final String[] IMAGE_EXTENSION = {"gif", "jpg", "png"};

    // 默认的 Banner
    private static final Banner DEFAULT_BANNER = new SpringBootBanner();

    // ...

    Banner print(Environment environment, Class<?> sourceClass, PrintStream out) {
        Banner banner = getBanner(environment);
        banner.printBanner(environment, sourceClass, out);
        return new PrintedBanner(banner, sourceClass);
    }

    // ...

    private Banner getBanner(Environment environment) {
        Banners banners = new Banners();
          // 优先打印 ImageBanner
        banners.addIfNotNull(getImageBanner(environment));
        // 没有设置 ImageBanner,则优先打印 TextBanner
        banners.addIfNotNull(getTextBanner(environment));
        if (banners.hasAtLeastOneBanner()) {
            return banners;
        }
        // ...
        // ImageBanner、TextBanner 都没有设置,则打印 Spring Boot 默认的 Banner
        return DEFAULT_BANNER;
    }

    // ...

}

默认的 Banner 值的主要内容由 SpringBootBanner 类的一个常量值定义:

class SpringBootBanner implements Banner {

    private static final String[] BANNER = {"", "  .   ____          _            __ _ _",
            " /\\\\ / ___'_ __ _ _(_)_ __  __ _ \\ \\ \\ \\", "( ( )\\___ | '_ | '_| | '_ \\/ _` | \\ \\ \\ \\",
            " \\\\/  ___)| |_)| | | | | || (_| |  ) ) ) )", "  '  |____| .__|_| |_|_| |_\\__, | / / / /",
            " =========|_|==============|___/=/_/_/_/"};

    // ...

}

如果我们想自定义 Banner,我们可以在项目的 resources 目录下放置 banner.txt 文件,从而改变 Banner 的打印。如我的 banner.txt 文件的内容为:

                     _    __               
    ____   ____ _   (_)  / /_   _____  ___ 
   / __ \ / __ `/  / /  / __/  / ___/ / _ \
  / /_/ // /_/ /  / /  / /_   (__  ) /  __/
 / .___/ \__,_/  /_/   \__/  /____/  \___/ 
/_/                                        

应用启动后打印的 Banner 信息被修改为:

                     _    __               
    ____   ____ _   (_)  / /_   _____  ___ 
   / __ \ / __ `/  / /  / __/  / ___/ / _ \
  / /_/ // /_/ /  / /  / /_   (__  ) /  __/
 / .___/ \__,_/  /_/   \__/  /____/  \___/ 
/_/                                        

prepareContext

prepareContext() 是其中非常重要的一个方法,该方法的作用在上一篇文章中就所有提及。

public class SpringApplication {

    // ...

    private void prepareContext(/* ... */) {
        // ...
        logStartupInfo(context.getParent() == null);
        logStartupProfileInfo(context);
        // ...
    }

    // ...

}

prepareContext() 通过 logStartupInfo()、logStartupProfileInfo() 两个方法,分别输出下面两句日志:

2022-09-08 08:28:22.964  INFO 54995 --- [           main] o.s.springweb.HelloWorldApplication      : Starting HelloWorldApplication using Java 11.0.12 on susamludeMac.local with PID 54995 (/Users/susamlu/code/java/spring-web/spring-web-helloworld/target/classes started by susamlu in /Users/susamlu/code/java/spring-web)
2022-09-08 08:28:22.968  INFO 54995 --- [           main] o.s.springweb.HelloWorldApplication      : No active profile set, falling back to 1 default profile: "default"

refreshContext

refreshContext() 也是其中的核心方法,Tomcat 的启动就发生在该方法的调用过程中。refreshContext() 最终会调用 AbstractApplicationContext 的 refresh() 方法,refresh() 又调用了自身的 onRefresh() 和 finishRefresh() 方法。

public abstract class AbstractApplicationContext extends DefaultResourceLoader
        implements ConfigurableApplicationContext {

    // ...

    public void refresh() throws BeansException, IllegalStateException {
        // ...
        onRefresh();
        // ...
        finishRefresh();
        // ...
    }

    // ...

}

其中 onRefresh() 实际调用的是 ServletWebServerApplicationContext 的 onRefresh() 方法,然后再通过 ServletWebServerFactory 获取 WebServer。

public class ServletWebServerApplicationContext extends GenericWebApplicationContext
        implements ConfigurableWebServerApplicationContext {

    // ...

    protected void onRefresh() {
        // ...
        createWebServer();
        // ...
    }

    // ...

    private void createWebServer() {
        // ...
        ServletWebServerFactory factory = getWebServerFactory();
        // ...
        this.webServer = factory.getWebServer(getSelfInitializer());
        // ...
    }

    // ...

}

ServletWebServerFactory 会创建 TomcatWebServer,创建 TomcatWebServer 的时候,它的 initialize() 方法会被自动调用,initialize() 会启动 Tomcat 并输出相关日志。

public class TomcatWebServer implements WebServer {

    // ...

    private void initialize() throws WebServerException {
        logger.info("Tomcat initialized with port(s): " + getPortsDescription(false));
        // ...
        this.tomcat.start();
        // ...
    }

    // ...

}
2022-09-08 08:28:24.900  INFO 54995 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2022-09-08 08:28:24.912  INFO 54995 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2022-09-08 08:28:24.913  INFO 54995 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.65]
2022-09-08 08:28:25.090  INFO 54995 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2022-09-08 08:28:25.091  INFO 54995 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 1910 ms

Tomcat 启动完,onRefresh() 也接着调用完成,再接着 finishRefresh() 会调用 TomcatWebServer 的 start() 方法,输出 Tomcat 启动完成的日志。

public class TomcatWebServer implements WebServer {

    // ...

    public void start() throws WebServerException {
        // ...
        logger.info("Tomcat started on port(s): " + getPortsDescription(true) + " with context path '"
                + getContextPath() + "'");
        // ...
    }

    // ...

}
2022-09-08 08:28:25.857  INFO 54995 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''

上面的方法都调用完后,最终又回到了 SpringApplication 的 run() 方法,run() 最后输出应用启动完成的日志。

public class SpringApplication {
    
    // ...

    public ConfigurableApplicationContext run(String... args) {
        // ...
        new StartupInfoLogger(this.mainApplicationClass).logStarted(getApplicationLog(), timeTakenToStartup);
        // ...
    }

    // ...
    
}
2022-09-08 08:28:25.873  INFO 54995 --- [           main] o.s.springweb.HelloWorldApplication      : Started HelloWorldApplication in 3.735 seconds (JVM running for 4.41)

整个流程,可以总结为以下一张图:

回顾

上一篇文章,我们以一张图展示了项目启动的流程,本文也同样总结成了一张图,对于这两张图所涉及到的过程,它们相互之间的顺序是怎么样的呢?

当我们把这两张图拿来对比,并对照相关的源代码,不难发现,SpringFactoriesLoader 的 loadSpringFactories() 方法是最先被触发的,接着,开始输出 Spring Banner,再接着,开始执行 logStartupInfo()、logStartupProfileInfo() 两个方法。上面方法都执行完之后,接着,SpringApplication 的 load() 方法开始执行,再接着就是配置类和自动配置类的解析。这些都执行完了之后,就开始启动 Tomcat,一直到整个项目启动完成。这当中的顺序,可以用下面一张图来表示:


三穆
1 声望1 粉丝

沉舟侧畔千帆过,病树前头万木春。