StopWatch计时异常:数据库调用方法为何显示0ms/纳秒级耗时?
StopWatch计时显示纳秒级/0ms的原因分析
1. 数据库操作的实际耗时远低于预期
你默认认为数据库连接+查询不可能少于1毫秒,但实际场景中这是完全可能的:
- 连接池复用连接:生产环境几乎都会用数据库连接池(如HikariCP、Druid),连接是提前初始化好的,获取连接的耗时可以忽略不计,不需要每次新建连接;
- 缓存命中:如果查询的数据量极小,或者命中了Oracle服务器端的Buffer Cache、应用层本地缓存,查询本身的耗时会短到毫秒以下,StopWatch统计的是真实执行时间,并非异常。
2. StopWatch的毫秒级统计存在精度截断
Spring的StopWatch底层基于System.nanoTime()实现高精度计时(Java 8+环境),但getTotalTimeMillis()方法会将纳秒数向下取整转换为毫秒。比如实际耗时0.8毫秒(800000纳秒),调用getTotalTimeMillis()会返回0,此时你的代码会切换到纳秒级显示,这是正常的精度转换结果,并非计时错误。
3. AOP切面未完整覆盖实际执行逻辑(低概率)
如果带@MethodStatistics注解的方法内部存在同一类内的方法调用,Spring AOP的动态代理机制不会拦截这类内部调用,导致StopWatch只统计了外层方法的空壳调用,未包含真正的数据库操作耗时。你可以在数据库操作代码处添加日志,验证这部分逻辑是否被纳入计时范围。
内容的提问来源于stack exchange,提问作者Jorg Heymans
相关产品推荐
相关产品推荐

