一次排查线上接口偶发异常耗时引起的思考!
一、引子
这要从线上的一个接口偶发异常耗时说起,事情往往不是你想象的样子,尤其是在排查问题的时候,切忌有先入为主的的某些判断。
二、问题:
接口监控图:显示每天总会有那么几次耗时特别长的请求。
三、排查:
1、直观的认识是“偶发”,每天零星的几个,不规律。
对于这种情况,第一感觉是因为服务的波动影响,因为没有服务能够达到100%的低延迟可用响应。
首先检查了相应时段的其它接口的响应情况,发现并没有相似的情景。由此可以基本上排除了服务波动的影响,但是也不是十分确定。
2、接口逻辑
逻辑l3是一个存在很久的历史业务逻辑,首先假定认为了它没有问题排除掉了(呵呵)。
l2是一个比较耗时的处理,首先的关注点放在了这里。l2是有超时设定的,最大超时为2s,但是我们的监控库里看到的最大的耗时是超过两秒的,或者考虑到其它处理逻辑的耗时,最坏的情况下,总的耗时是不应该超过3s的。为了确认l2服务的稳定性,线上添加了相应的监控,观察到最大耗时是在超时限定范围内的。因此排除掉此处的问题,
3、不得已而为之
经过以上几步的排查,现有的信息已经不足以定位问题了。只能把接口里的每一步逻辑耗时全部统计记录来进一步排查(其实,内心是非常拒绝的)。
四、StopWatch
StopWatch很多地方都提供了,Spring、Apache、Guava。
1、Spring示例:
♣ id标识当前的StopWatch,比如统计一个接口的耗时,可以使用接口名称作为标识,从而在输出端进行识别。
♣ 内部有task概念,用以表示内部每一阶段的执行逻辑,比如获取用户信息->获取资金信息->交易逻辑流转过程。
♣ 的格式化输出比较明晰,包括StopWatch标识,任务标识,每个任务的耗时及总占比。
public static void springStopWatch() throws InterruptedException {
StopWatch stopWatch = new StopWatch("spring_stopwatch");
stopWatch.start("a"); //开始任务a
Thread.sleep(1000);
stopWatch.stop(); //任务a执行完毕
stopWatch.start("b"); //开始任务b
Thread.sleep(2000);
stopWatch.stop(); //任务b执行完毕
stopWatch.start("c"); //开始任务c
Thread.sleep(100);
stopWatch.stop(); //任务c执行完毕
System.out.println(stopWatch.prettyPrint());
}
输出:
StopWatch 'spring_stopwatch': running time (millis) = 3111
-----------------------------------------
ms % Task name
-----------------------------------------
01002 032% a
02006 064% b
00103 003% c
2、Apache StopWatch:
这里有个split概念,我愿意称之为时间“锚点”,当你执行完split操作后,在下一次执行split之前,你可以在任何时候获取开始时间到执行split的时间点之间的时间间隔:
supend-resume:挂起、恢复,很容易理解,暂停计时、恢复继续计时:
public static void apacheStopWatch() throws InterruptedException {
org.apache.commons.lang3.time.StopWatch stopWatch = org.apache.commons.lang3.time.StopWatch.createStarted();
Thread.sleep(1000);
stopWatch.stop(); //结束计时
System.out.println("normal: " + stopWatch.getTime());
//split test
stopWatch.reset();
stopWatch.start();
Thread.sleep(1000);
stopWatch.split(); //时间锚点
Thread.sleep(1000);
System.out.println("split: " + stopWatch.getSplitTime()); //开始到时间锚点的间隔
//suspend
stopWatch.reset();
stopWatch.start();
Thread.sleep(1000);
stopWatch.suspend(); //挂起watch
Thread.sleep(1000); //期间的时间是不计入总时间的
stopWatch.resume(); //恢复watch
Thread.sleep(1000);
stopWatch.stop();
System.out.println("suspend_resume: " + stopWatch.getTime());
}
输出:
normal: 1002
split: 1004
suspend_resume: 2009
3、Guava:
just StopWatch
public static void guavaStopWatch() throws InterruptedException {
Stopwatch stopwatch = Stopwatch.createStarted();
Thread.sleep(1000);
stopwatch.stop();
System.out.println(stopwatch.elapsed(TimeUnit.MILLISECONDS));
stopwatch.reset();
stopwatch.start();
Thread.sleep(2000);
stopwatch.stop();
System.out.println(stopwatch.elapsed(TimeUnit.MILLISECONDS));
}
输出:
1001
2004
五、结论
这里采用的是Spring的StopWatch,四个Task,总耗时及分耗时不用额外的记录处理,对于总耗时超过一定值的请求,打印StopWatch明细:
- 如何利用ETW(Event Tracing for Windows)记录日志
- 如何利用ETW(Event Tracing for Windows)记录日志
- ASP.NET MVC以ValueProvider为核心的值提供系统: DictionaryValueProvider
- ASP.NET MVC如何实现自定义验证(服务端验证+客户端验证)
- .NET Core的文件系统[2]:FileProvider是个什么东西?
- Python多线程怎样优雅的响应中断异常
- .NET Core的文件系统[3]:由PhysicalFileProvider构建的物理文件系统
- .NET Core的文件系统[4]:由EmbeddedFileProvider构建的内嵌(资源)文件系统
- 学习July博文总结——支持向量机(SVM)的深入理解(下)
- 在gridview和datagrid里设置列宽
- ASP.NET MVC的Model元数据与Model模板:将”ListControl”引入ASP.NET MVC
- .NET Core的文件系统[5]:扩展文件系统构建一个简易版“云盘”
- 全球15%工作将被自动化,中国1亿人将面临失业
- ASP.NET MVC的Model元数据提供机制的实现
- JavaScript 教程
- JavaScript 编辑工具
- JavaScript 与HTML
- JavaScript 与Java
- JavaScript 数据结构
- JavaScript 基本数据类型
- JavaScript 特殊数据类型
- JavaScript 运算符
- JavaScript typeof 运算符
- JavaScript 表达式
- JavaScript 类型转换
- JavaScript 基本语法
- JavaScript 注释
- Javascript 基本处理流程
- Javascript 选择结构
- Javascript if 语句
- Javascript if 语句的嵌套
- Javascript switch 语句
- Javascript 循环结构
- Javascript 循环结构实例
- Javascript 跳转语句
- Javascript 控制语句总结
- Javascript 函数介绍
- Javascript 函数的定义
- Javascript 函数调用
- Javascript 几种特殊的函数
- JavaScript 内置函数简介
- Javascript eval() 函数
- Javascript isFinite() 函数
- Javascript isNaN() 函数
- parseInt() 与 parseFloat()
- escape() 与 unescape()
- Javascript 字符串介绍
- Javascript length属性
- javascript 字符串函数
- Javascript 日期对象简介
- Javascript 日期对象用途
- Date 对象属性和方法
- Javascript 数组是什么
- Javascript 创建数组
- Javascript 数组赋值与取值
- Javascript 数组属性和方法
- Java自动化测试(web自动化测试框架 28)
- 你想要拥有自己的搜索引擎吗?
- JAVA三年面试总结,金九银十,你准备好了吗?
- Best Cow Line(POJ 3617)
- Flask单点登录竟然只要几行代码就能搞定!
- 区间调度问题
- 迷宫的最短路径
- Lake Counting (POJ No.2386)
- 部分和问题(DFS)
- 为什么 React Hooks useState 更新不符预期?
- 技术分享 | MySQL 使用 MariaDB 审计插件
- 第12期:压缩表性能监测
- 第05期:使用 prometheus 监控 clickhouse 集群
- 这 6 点知识让我对 JavaScript 的对象有了更进一步的了解
- Linux进程间通信(中)之信号、信号量实践