案例诊断:“交易耗时8S”缉凶记

背景

某日上午,小集购买a产品失败,页面弹出“系统异常,请稍后重试”的报错,便联系了技术团队的开发小成。

“小成,我刚才尝试买a产品一直显示系统异常,是不是有什么问题呢?”开发小成接到电话后,迅速着手排查,同时也收到了系统监控平台的告警。

小成立刻登录系统应用服务器,发现交易耗时在8s左右。经过一系列紧张的故障排查和恢复工作,虽然过程艰难,但最后还是成功地恢复了业务。

解决过程

【DAY1】

“交易的耗时为什么会这么久?是不是内存资源不足引起的?”

小成立即查看了应用服务所在的公有云服务器的资源状态,发现服务器的VM系统大量OOM报错,即使尝试重启Tomcat,也是失败。

“是不是有什么业务层的程序大量消耗资源导致?”

带着这个问题,小成继续一步步排查。半小时左右,小成发现合作机构的前置T应用上有大量的Close_wait连接,应用提示open too many files。大量Java的应用报错Java.io.IO.Exception: Broken Pipe.

为了尽快恢复业务,小成尝试重启了Tomcat应用,但错误依旧存在,尝试修改open files和max user processes参数,未见明显效果。小成又再试着在弹性服务器上分别Telnet本地端口和对方端口甚至重启了服务器。这些都无济于事,错误依然存在。

发现这些常用恢复方式不起作用,小成调整思路,看业务平台是不是有问题。果不其然发现应用平台上持续大量业务报错,报错信息集中在产品中心的捞取数据同步的定时任务。

“难道是这个定时任务的数据量增大导致的?”

小成确认了当日的定时同步数据的任务业务量级,发现每分钟1万左右,平均每秒(QPS)300~350之间(与日常调用量持平)。

“既然定时任务的量级未变,为什么会大量报错?”

业务恢复争分夺秒,小成申请停掉可疑的定时任务,发现不见效,尝试业务流量切换到备用集群观察。

流量切换后,问题恢复了。

“切换到备用集群竟然可以恢复,难道是老集群的问题?”

想着定时任务还停着,小成建议申请恢复定时任务,数据同步定时任务再次被拉起。

这时已经过去了近两个小时。虽然切换新集群业务恢复,定时任务也恢复运行,但根本原因还是没查明。小成开始复盘整个过程,思考各个疑点。

为什么数据同步定时任务会大量报错?虽然报错,为什么切换到新集群会恢复?

这时电话又响起了:“小成,备用集群也出事了!”

小成脑子快速闪过,“基本确定是定时任务的问题了”。

小成申请再次停止数据同步任务,经同意后,立即执行。执行后,业务开始逐渐正常。时间已经到了下午。

小成和团队人员紧急召开复盘会议,基于业务影响可能性的评估,决策对业务主链路进行隔离。当天下午紧急对业务链路进行隔离操作,并且在1个多小时内完成业务流量验证通过。

不知不觉一下午时间就这样过去了,小成理了理思路,决定把问题来龙去脉理清楚,于是发起了次日集中问题排查的会议邀约,参与人员涉及多方技术团队。

【DAY2】

通过对监控数据的梳理,小成发现当天机房的负载均衡服务器和弹性计算服务器有异常流量,且网络还有丢包情况。但是这流量的来源无法查明。另外T应用hang住的时候关系型数据库服务上的耗时急剧增加。

【DAY3~DAY4】

基于这一点,技术团队就此问题进一步深挖。通过复查所有相关SQL语句和查询数据量以及数据库数据量,试图找到病根,但是最终发现并没有异常。

那到底是什么变更导致数据库响应慢的?

技术人员再次调整思路,尝试在SIT环境 (线下测试环境)mock SQL 查询超时的情况,果然,重现了关系数据库服务查询耗时急剧增加的现象。并且T应用上出现大量Close_wait的连接,直到应用服务器上的资源耗尽,导致应用hang住。

【DAY5】

业务一切正常,但是SQL缓慢的原因还无法具体定位。

不过,业务涉及数据同步定时任务查询的SQL倒是还存在不少的优化空间,业务技术人员在当晚就通过索引优化的方式固定执行计划。

【DAY6】

第6天,小成邀请了数据库团队和公有云等技术专家团队参与到了问题排查中。

终于问题的根源逐渐水落石出,数据库和云服务器专家们就这个可疑的数据库服务响应慢的问题进行层层排查。

深入分析

(1)应用服务器单台网卡为什么有大量异常流量?

这是因为服务器主机的日志同步机制运行时,会每5分钟读取一次日志,从而引起异常流量。

(2)应用服务端为什么会大量Close Wait?

Close Wait产生的原因在于数据库服务端等待超时后,主动断开连接,如果应用服务端在数据库断开之后能够响应及时关闭,就不会积攒大量Close Wait,但是应用服务端在当天问题发生时并未马上关闭无用连接,所以大量的CloseWait状态过多,导致主机资源耗尽。

当天排查也发现合作机构前置应用在网关关闭连接后,业务查询还未结束时,前置应用的网关连接不会关闭。这一事实佐证了上面这一点。

(3)应用服务端为什么会大量报错“open too many files”?

应用服务器可以open的文件数有上限,通常不会到达这个阀值。如果出现那可能就是有文件句柄没有及时释放。由于前面有大量处于close_wait的tcp连接,每个连接对应一个套接字(socket),也对应一个文件句柄,这是导致报错的主要原因。

(4)数据库服务的耗时是否和数据库主机的CPU利用率有关?

分析:

数据库主机的各个逻辑CPU在问题发生期间的监控数据都是正常,该因素排除。

监控佐证:

图3-1所示是数据库实例采集到的CPU的平均利用率监控信息,从监控来看,并没有明显变化。

图3-1  CPU平均利用率

5)会不会是数据库主机磁盘IO有问题?

分析:

磁盘IO监控包括每秒读写IO次数,每秒读写IO吞吐量、每个读写IO的平均响应时间,磁盘当前队列长度。

数据库服务的DB文件分为数据文件和日志文件,日志文件存放于D盘,数据文件存放于E盘,Tempdb的文件在D盘。

模拟当天业务场景和大致时间点,从监控(如图3-2所示)可以看出,在09:25以前D盘的活动比较多,但总体都在正常范围。25分之后,E盘在45分左右有个高峰,但是峰值依然远低于磁盘的能力(最大IOPS14000)。磁盘IO平均响应时间供参考。当磁盘IO压力过大或者出现访问问题时,那个响应时间会有值。正常情况下,数据都非常小(小于1),总体来说数据库主机的IO负载也很低,此因素排除。

图3-2  C和D盘的每秒写吞吐量

(6)是不是和业务SQL性能有关 ?

分析:

关于SQL变慢,通过分析数据库日志发现,拉取同步数据的关键SQL缺乏正确的索引,进而导致其执行计划不是最优,理论分析这个执行计划也是不稳定的。随着业务同步数据的全量替换,以及表统计信息短时间内不能及时更新,SQLserver可能会根据查询参数比对统计信息而调整执行计划。

推测在09:35左右,这个SQL的执行计划发生变化导致性能出现更差的情形,而高并发的访问加剧了这个性能的问题。这一点表现在DB上就是CPU利用率升高,CPU利用率变高,反过来会影响SQL的性能(针对全体SQL)。

09:37前后相邻的两个诊断报告的等待事件表明Buffer Latch最大等待延迟也增加180ms(这表示Buffer Latch等待更严重)。调用端观察结果就是SQL执行时间变长的SQL比例越来越多。

关于SQL变慢,还需要关注的是,相对于问题发生前一天,数据库连接增长了300, CPU利用率也同比增长很多,从现有的数据很难断定是访问请求增加导致实例压力变化,还是实例压力变化导致访问增多(触发重试逻辑)。

这是一个恶性循环的过程,根源就是SQL执行缺乏正确的索引且并发很高!

监控佐证(如图3-3、3-4、3-5所示)。

SQL耗时分析报告,如表3-2所示。

时间段SQL执行成本(平均逻辑读)
09:25:00~09:37:182106
09:37:18~11:30:18203261
11:30:18~13:26:18813672

表3-2  SQL耗时分析

重点问题SQL,SQL请求很高,且没有走上合适的索引(如图3-6所示)。

图3-6  问题SQL

问题当日09:02~09:37 期间总执次数:71163 次(实际从09:25开始),平均消耗时间0.72s。

问题当日09:31~09:56 期间总执次数:22914 次,平均消耗时间16.0s。

分析:

视图ViewEstimateIntrdayForE的定义(如图3-7所示)。

图3-7  视图定义

表FundData.dbo.SecuCodeRelationSMCode的索引(如图3-8所示)。

图3-8  SQL索引情况

小结

本文这个案例的发生,一层层剥开来看,最后还是SQL执行计划不佳引起。因为缺乏合适的索引,所以原SQL的执行计划很可能处于不稳定的状态,即SQLServer可能会根据压力状况、数据量、统计信息以及传参数值来判断当前的执行计划是否为最优,如果数据库基于内存中的信息判断有更好的选择(从数据库角度判断,这很可能是个更加错误的选择),就改变当前执行计划,从而导致性能上可能出现更大的延时,再加上高并发,就进一步放大了这一性能问题。

基于本次问题的整个过程处理和原因分析,可以总结出以下几点措施和优化点来避免类似问题重复发生:

(1)如何避免服务器异常流量?

优化服务器主机日志同步方式,可考虑迁移现有成熟的日志同步工具。

(2)大量close wait的异常怎么才能避免?

从业务上下游主链路梳理超时时间参数和SQL超时设置,对齐超时标准,统一调优。

(3)如何避免“open toomany files”?

检查文件读写操作、socket通讯是否正常。

(4)业务如何避免同类SQL执行计划问题发生?

针对TOP10 SQL集中review 执行计划和索引设置,避免触发SQLServer的可能的潜在问题。

数据库主机虽有CPU等系统监控,但是并无执行计划的监控,完善SQL执行计划的监控覆盖。

(5)线上问题迅速发现

完善依托公有云的业务应用监控,尤其是远程调用和数据库访问的监控数据完善,便于后续第一时间发现问题。

完善添加关系型数据库SQL执行计划监控项,添加数据库容量带宽和连接数的监控。

(6)问题快速定位

线上问题快速定位和排查能力提升,定位问题需要分阶段定位,首先定位外部系统原因,数据库原因,网络原因还是应用程序原因。本次在定位是数据库的原因耗时太长,丧失了数据库层面的第一现场。

问题处理环节,需以最快的时间协同不同团队之间的响应处理,避免错失问题排查的最佳时间窗口。

本文选自《逆流而上》

原文链接:https://mp.weixin.qq.com/s/8uFKZcPWN2P4_BKhWHZmhg

Image placeholder
gaosanshi
未设置
  50人点赞

没有讨论,发表一下自己的看法吧

推荐文章
从零开始入门 K8s | K8s 的应用编排与管理

作者|张振阿里云高级技术专家一、资源元信息1.Kubernetes资源对象我们知道,Kubernetes的资源对象组成:主要包括了Spec、Status两部分。其中Spec部分用来描述期望的状态,St

使用kubei一步部署k8s高可用集群(包含docker安装、k8s组件安装、master初始化和加入nodes节点)

kubei(kubernetesinstaller)是一个go开发的用来部署kubernetes高可用集群的命令行工具,该工具可在Windows、Linux、Mac中运行kubei原理:通过ssh连接

K8s有多热?传统银行转型拥抱Kubernetes案例

Kubernetes已经成为标准的基础设施API,像RedHat、Mesosphere(现在的D2IQ)和Pivotal等供应商都无法避免。如果您希望使企业能够合理构建应用程序,那么Kubernete

使用Jupyter NoteBook进行IB查询和交易,以及使用算法交易示例

在搞好IB盈透接口后,试了下客户端交易,但是最终目的还是使用程序化交易。发现vnpy已经提供的Script_engine来支持JupyterNoteBook交易的,而且非常方便调用。 这里就用写了基于

IT168企业存储月刊|十月多款新产品面世,上半年市场“交卷”

对于企业数据管理与存储市场而言,十月似乎是一个忙碌的月份。全球各大厂商相继发布新的产品与解决方案,为市场提供更多选择,帮助推动企业数字化升级。此外,IDC也发布了最新的市场调查报告,涉及企业级外部存储

JavaScript中对“this”的简单理解

1.this的奥秘很多时候,JS中的this对于咱们的初学者很容易产生困惑不解。this的功能很强大,但需要一定付出才能慢慢理解它。对Java、PHP或其他标准语言来看,this表示类方法中当前对象的

DTCC2019 :“数据架构设计实践专场”等您来!

  2019年5月8日~5月10日,由IT168旗下ITPUB企业社区平台主办的第十届中国数据库技术大会(DTCC2019),将在北京新云南大酒店召开。本次大会将以“数据风云,十年变迁”为主题,邀请百

数据科学家的高级能力:“讲故事”

在不算太遥远的过去,业界对数据科学家的评判主要依据于他们发现、理解、管理和综合信息的能力。随着数据环境的不断发展和计算能力的不断提高,编码技能变得越来越重要。随着时间的推移,又出现了更加细致入微的技能

阿里巴巴向全社会开放黑科技:“泡在水里”的服务器

为了让数据中心更绿色,阿里工程曾将服务器“泡在水里”进行散热,节能超70%,今天这项黑科技的神秘面纱被揭开。2020年1月6日,阿里巴巴宣布将“浸没式液冷数据中心技术规范”向全社会开放。这项规范旨在用

耗时6年生成代码1.6亿行,农业银行大数据平台打造攻略!

摘要: 耗时6年,135个项目,8000页需求,累计投入11000多人月,生成的代码行1.6亿行,支持了8大业务领域,33条业务线,120多个应用场景,这就是中国农业银行大数据平台。近日,中国人民银行

从零开始入门 K8s:应用编排与管理

一、需求来源 背景问题 首先来看一下背景问题。如下图所示:如果我们直接管理集群中所有的Pod,应用A、B、C的Pod,其实是散乱地分布在集群中。 现在有以下的问题: 首先,如何保证集群内可用Pod的

AWS vs K8s 是新时代的 Windows vs Linux?

作者:IanMiell是开源程序员、演讲师、作家和博客写手以前……如果你与我一样,年过四十,又在IT行业工作,恐怕还记得每个人使用Windows,一小群但越来越多的人在业余时间埋头编译Linux的年代

Dubbo 在 K8s 下的思考

作者|曹胜利  ApacheDubboPMC导读:Dubbo作为高性能JavaRPC框架的刻板印象早已深入人心,在CloudNative的架构选型上,SpringCloud或许才是业界的优先选择。实际

超大规模商用 K8s 场景下,阿里巴巴如何动态解决容器资源的按需分配问题?

导读:资源利用率一直是很多平台管理和研发人员关心的话题。本文作者通过阿里巴巴容器平台团队在这一领域的工作实践,整理出了一套资源利用提升的方案,希望能够带给大家带来一些讨论和思考。引言不知道大家有没有过

交易所源码出售

分享链接:https://www.v2ex.com/t/624890github地址指数型差价合约交易所系统、ICFD指数型差价合约交易所、BTC比特币杠杠交易、领先数字货币杠杆交易所(高达100倍杠

一个多业务、多状态、多操作的交易链路?闲鱼架构这样演进

前言双十一刚刚结束,成交额2684亿震惊全世界,每秒订单峰值达54.4W笔。在闲鱼2000万DAU,交易数额同样增长迅速的今天,我们如何保障交易链路的稳定与快速支撑业务?这篇文章从客户端开发的角度,介

IBM收购红帽案已完成交易,混合云竞争格局变得更微妙!

自从去年年底IBM放出消息要收购红帽后,这个开源软件领域的最大并购案,就一直牵动着无数人的神经。而现在,这笔价值340亿美元的交易,终于成为既定事实。本周二,IBM和红帽共同宣布,已通过现金的形式正式

杭州银行批量交易平台(HZBAT)技术内幕

1 概述杭州银行批量交易平台(HZBAT)是我基于DC4C自研的面向批量交易的技术平台。DC4C是我在2015年完全独立自研的分布式批量计算框架。目前HZBAT已用于综合积分系统(2015年投产)、E

MySQL 亿级数据数据库优化方案测试-银行交易流水记录的查询

作者:逸宸a链接:https://www.jianshu.com/p/cbdef47fb837对MySQL的性能和亿级数据的处理方法思考,以及分库分表到底该如何做,在什么场景比较合适?比如银行交易流水

从理论到案例,请收下这篇 Nginx 监控运维干货

Nginx(“enginex”)是一个开源、免费、高性能的HTTP和反向代理服务器,也可以用于IMAP/POP3代理服务器。充分利用Nginx的特性,可以有效解决流量高并发请求、cc攻击等问题。本文

ElasticSearch 亿级数据检索案例实战

一、前言数据平台已迭代三个版本,刚开始遇到很多常见的难题,终于有时间整理一些已完善的文档了,在此分享一下。希望能帮助大家少走些弯路,在此篇幅中偏重于ES的优化。关于HBase,Hadoop的设计优化估

Elasticsearch 亿级数据检索性能优化案例实战!

一、前言数据平台已迭代三个版本,从头开始遇到很多常见的难题,终于有片段时间整理一些已完善的文档,在此分享以供所需朋友实现参考,少走些弯路,在此篇幅中偏重于ES的优化,关于HBase,Hadoop的设计

超8千Star,火遍Github的Python反直觉案例集!

大数据文摘授权转载作者:SatwikKansal译者:暮晨Python,是一个设计优美的解释型高级语言,它提供了很多能让程序员感到舒适的功能特性。但有的时候,Python的一些输出结果对于初学者来说似

SQL优化案例-定位系统中大量的rollback(十八)

系统中logfilesync比较严重,查看存储都没有问题,logfileparallelwrite很低,时间分布直方图也没问题数据库中提交和回滚操作比较频繁,每秒1000多次,rollback占比1/

医疗保健案例研究:怎样用深度学习检测疟疾

导言本文中,我们将集中讨论人工智能(AI)与流行的开源工具、技术和框架如何被用于发展和改善医疗行业。俗话说,健康就是财富。在这篇文章中,我们将探讨如何利用人工智能来检测一种致命的疾病–疟疾,以及如何建