一次服务启动慢问题排查

这篇具有很好参考价值的文章主要介绍了一次服务启动慢问题排查。希望对大家有所帮助。如果存在错误或未考虑完全的地方,请大家不吝赐教,您也可以点击"举报违法"按钮提交疑问。

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

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

一次服务启动慢问题排查

一般服务启动慢原因主要有:
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参数配置。

一次服务启动慢问题排查

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

一次服务启动慢问题排查

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

一次服务启动慢问题排查

解决问题:
从图可以看出问题就是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做升级,根据经验这就是问题所在了。

一次服务启动慢问题排查

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

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

一次服务启动慢问题排查

欢迎关注我的github:https://github.com/jmilktea/jtea文章来源地址https://www.toymoban.com/news/detail-602183.html

到了这里,关于一次服务启动慢问题排查的文章就介绍完了。如果您还想了解更多内容,请在右上角搜索TOY模板网以前的文章或继续浏览下面的相关文章,希望大家以后多多支持TOY模板网!

本文来自互联网用户投稿,该文观点仅代表作者本人,不代表本站立场。本站仅提供信息存储空间服务,不拥有所有权,不承担相关法律责任。如若转载,请注明出处: 如若内容造成侵权/违法违规/事实不符,请点击违法举报进行投诉反馈,一经查实,立即删除!

领支付宝红包 赞助服务器费用

相关文章

  • 记一次.Net Core程序启动失败的排查过程

    阅文时长 | 2分钟 字数统计 | 3212字符 主要内容 | 1、引言背景 2、排查.NetCore启动失败详细过程 3、声明与参考资料 『记一次.Net Core程序启动失败的排查过程』 编写人 | SCscHero 编写时间 | 2021/12/23 PM2:6 文章类型 | 系列 完成度 | 已完成 座右铭 每一个伟大的事业,都有一个微不足

    2024年02月05日
    浏览(47)
  • 【记一次线上事故的排查思路】- CPU飙升问题排查

    由于项目排期较紧,临时从其他组调来三个开发资源帮我一起做项目,难免上线的时候大家的需求一块上线。 问题来了,上线三天后,线上CPU总是莫名奇妙的突然飙升,飙升后CPU并未降下来,而是一直处在高点。 由于是线上导致的问题,CPU超限后,会自动重启项目,未能保

    2024年01月23日
    浏览(49)
  • 一次日志配置未生效问题排查记录

    某天排查业务问题时,在我司的日志收集平台上,未能发现相关业务服务接口访问日志。经过和相关同事确定,发现业务服务未能将接口访问日志吐到日志收集平台,由此开启一段有点漫长的排查之旅。 业务服务是典型的SpringBoot web应用,日志记录采用slf4j+log4j2组合。 通过applica

    2024年02月11日
    浏览(42)
  • 记一次Apache HTTP Client问题排查

    通过日志查看,存在两种异常情况。 第一种:开始的时候HTTP请求会报超时异常。 762663363 [2023-07-21 06:04:25] [executor-64] ERROR - com.xxl.CucmTool - CucmTool|sendRisPortSoap error,url:https://xxxxxx/realtimeservice/services/RisPort org.apache.http.conn.HttpHostConnectException: Connect to xxx [/xxx] failed: 连接超时 第二种

    2024年02月12日
    浏览(61)
  • 一次生产docker MTU=1500问题排查解决

    和业务方进行联调,业务方调用我方服务, 我方服务部署在虚拟机的docker容器中 提供grpc服务, 通过公网vip lvs到宿主机端口 联调发现 ping 和 telnet我方端口都正常, 但是通过grpc协议调用不通,一直超时 在容器上和lvs上tcpdump抓包发现了问题 容器内抓包: lvs上抓包到宿主机:

    2024年04月16日
    浏览(30)
  • 记一次jedis连接池顽固问题排查与修改

    这辈子不想再看到jedisBrokenPipe!!   测试环境运行16天后报错信息: 05:42:32.629 [http-nio-8093-exec-2] ERROR o.a.c.c.C.[.[.[.[dispatcherServlet] - [log,175] - Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is redis.clients.jedis.exceptions.JedisCon

    2023年04月21日
    浏览(58)
  • 【问题排查篇】一次业务问题对 ES 的 cardinality 原理探究

    作者:京东科技 王长春 小编工作中负责业务的一个服务端系统,使用了 Elasticsearch 服务做数据存储,业务运营人员反馈,用户在使用该产品时发现, 用户后台统计的订单笔数和导出的订单笔数不一致 ! 交易订单笔数不对,出现差错订单了?这一听极为震撼!出现这样的问

    2024年02月03日
    浏览(38)
  • 记一次 .Net+SqlSugar 查询超时的问题排查过程

    环境和版本:.Net 6 + SqlSuger 5.1.4.*   ,数据库是mysql 5.7 ,数据量在2000多条左右 业务是一个非常简单的查询,代码如下: tb_name 下配置了一对多的关系导航,但是执行时没有include导航属性,当执行上述代码时,查询非常慢,甚至会超时报错: The Command Timeout expired before the o

    2024年02月07日
    浏览(41)
  • 记一次Oracle归档日志异常增长问题的排查过程

    Oracle归档日志是Oracle数据库的重要功能,用于将数据库的重做日志文件(Redo Log)保存到归档日志文件(Archive Log)中。归档日志的作用是提供数据库的备份和恢复功能,以及支持数据库的持续性和数据完整性。 当数据库处于归档模式时,数据库引擎会将已经写满的重做日志

    2024年02月14日
    浏览(50)
  • 记一次 MySQL timestamp 精度问题的排查 → 过程有点曲折

    下午正准备出门,跟正刷着手机的老妈打个招呼 我:妈,今晚我跟朋友在外面吃,就不在家吃了 老妈拿着手机跟我说道:你看这叫朋友骗缅北去了,tm血都抽干了,多危险 我:那是他不行,你看要是吴京去了指定能跑回来 老妈:还吴京八经的,特么牛魔王去了都得耕地,唐

    2024年02月01日
    浏览(54)

觉得文章有用就打赏一下文章作者

支付宝扫一扫打赏

博客赞助

微信扫一扫打赏

请作者喝杯咖啡吧~博客赞助

支付宝扫一扫领取红包,优惠每天领

二维码1

领取红包

二维码2

领红包