• 一次服务启动慢问题排查


    随着时间推移,参与开发的人员越来越多,项目代码也会越来越复杂,需要我们有意识的定期对代码进行优化,有问题及时解决,避免技术债务越积越多。
    这不本人就遇到一个服务启动慢的问题,印象中服务启动是比较快的,一般也就20几秒,但这次开发一个需求发现服务启动要接近1分钟,这对本地开发调试,测试同学测试都是非常不方便的,影响工作效率。

    启动服务后观察日志,发现在最后一行这里卡了好久,但没有更有帮助的日志信息打印正在做什么。从图看起来像是xxl job的问题,但这是很早就引入了的,以前启动并不会慢,通过打断点也可以看出xxl job的初始化并没有阻塞。

    image

    一般服务启动慢原因主要有:
    1.程序太大了,加载的bean非常多,默认情况下spring没有使用异步加载,如果bean太多可能导致启动慢。
    2.在启动时做一些业务初始化,如使用@PostConstruct,在方法内进行接口调用,数据库查询等IO操作,可能导致服务启动慢。
    3.在启动时做一些框架初始化,如使用数据库orm框架,通常需要加载数据库元信息,如果数据库表过多,加载时间长,可能导致服务启动慢。

    那要怎么排查这个问题呢?
    恰好在github上看到一个工具就可以发现问题所在,spring-startup-analyzer,可以分析spring应用启动过程。

    spring-startup-analyzer

    使用步骤非常简单:
    1.下载最新的包,放到用户目录下,注意最好放到用户目录下,否则可能会有问题。
    2.添加启动命令

    -Dspring-startup-analyzer.app.health.check.endpoints=http://localhost:8020/actuator/health -javaagent:C:/Users/huangyb1/spring-startup-analyzer/lib/spring-profiler-agent.jar
    

    -Dspring-startup-analyzer.app.health.check.endpoints 是健康检查的url,当这个接口返回200就表示服务启动完成了。
    -javaagent 配置为上面下载的包路径
    3.启动观察有如下日志表示正常,8065断开可以查看分析报告,可以通过-Dspring-startup-analyzer.admin.http.server.port参数配置。

    image

    服务启动后分析结果如下:

    image

    可以看到dslContext花费了23秒多,占用了接近一半的时间了。那这个是不是就是在上面xxl job日志后卡住的原因呢?我们看如下的详细过程,发现确实如此。

    image

    解决问题:
    从图可以看出问题就是dlsContext这个加载慢导致,并且它是一个org.jooq.impl.DefaultDSLContext,由org.jooq.impl.DefaultConfiguration导入。
    jooq是什么?jOOQ 从您的数据库生成 Java 代码,并允许您通过其流畅的 API 构建类型安全的 SQL 查询。
    它可以实现将java代码翻译成sql语句,如:

    create.select(AUTHOR.FIRST_NAME, AUTHOR.LAST_NAME, count())
          .from(AUTHOR)
          .join(BOOK).on(AUTHOR.ID.equal(BOOK.AUTHOR_ID))
          .where(BOOK.LANGUAGE.eq("DE"))
          .and(BOOK.PUBLISHED.gt(date("2008-01-01")))
          .groupBy(AUTHOR.FIRST_NAME, AUTHOR.LAST_NAME)
          .having(count().gt(5))
          .orderBy(AUTHOR.LAST_NAME.asc().nullsFirst())
          .limit(2)
          .offset(1)
    

    将被翻译成

    SELECT AUTHOR.FIRST_NAME, AUTHOR.LAST_NAME, COUNT(*)
    FROM AUTHOR
    JOIN BOOK ON AUTHOR.ID = BOOK.AUTHOR_ID
    WHERE BOOK.LANGUAGE = 'DE'
    AND BOOK.PUBLISHED > DATE '2008-01-01'
    GROUP BY AUTHOR.FIRST_NAME, AUTHOR.LAST_NAME
    HAVING COUNT(*) > 5
    ORDER BY AUTHOR.LAST_NAME ASC NULLS FIRST
    LIMIT 2
    OFFSET 1
    

    说实话,本人不太喜欢这种书写方式,这种方式看起来并不直观,还没法直接拿这条sql语句出来执行,这种方式比较适合一些sql语句很简单的场景。
    我们的项目使用的是mybatis plus,也没有用到jooq,那它是怎么来的呢?通过maven dependency analyzer可以看出,它是由sharding-jdbc带入的,前段时间刚好有同学对sharding-jdbc做升级,根据经验这就是问题所在了。

    image

    上github也可以看到我们使用这个版本的sharding的jooq确实会导致服务启动慢,参见issues,官方下一个小版本就修复这个问题。

    解决方式也很简单,升级一些sharding-jdbc即可,通过上面的分析知道也可以排除jooq依赖,@SpringBootApplication(exclude = {JooqAutoConfiguration.class})。
    解决后重启服务观察到,jooq的初始化没有了,服务启动快了20多秒。

    image

    欢迎关注我的github:https://github.com/jmilktea/jtea

  • 相关阅读:
    Leetcode刷题Day8-------------字符串
    [附源码]计算机毕业设计基于SpringBoot动漫电影网站
    QML自定义BusyIndicator样式
    实现自动化构建与集成:Jenkins与SVN整合的指南
    决策树算法
    JAVA艾灸减肥管理网站计算机毕业设计Mybatis+系统+数据库+调试部署
    复杂环境下多移动机器人路径规划研究附Matlab代码
    软件配置 | Git下载、安装及卸载
    iPhone手机记笔记工具选择用哪个
    beanstalkd 启动跟停止【经常使用 nohup 和 & 配合来启动程序,如: nohup ./test &同时免疫SIGINT和SIGHUP信号】
  • 原文地址:https://www.cnblogs.com/jtea/p/17579628.html