Carte+kettle+mysql性能问题定位分析记录
通过Carte服务对kettle转换进行压力测试,以20并发为基准,通过不断的优化,对比测试结果如下:
20并发测试结果(持续7分钟) | 无Redis | 加Redis |
优化Carte内存 使用配置 |
加CPU和内存 (压15小时) |
Total Throughput (bytes) 总吞吐量 |
5,079,582 | 111,814,589 | 703,321,332 | |
Average Throughput (bytes/second) 吞吐率 |
11,624 | 264,963 | 1,798,776 | |
Total Hits 总点击量 | 1,458 | 7,245 | 17,615 | |
Average Hits per Second 点击率 |
3.336 | 17.168 | 45.051 | |
Average Response Time 平均响应时间 |
22.608秒 | 4.366秒 | 1.645秒 | 1.378秒 |
90 Percent Response Time 90%请求响应时间 |
35.614秒 | 22.959秒 | 3.828秒 | 2.351秒 |
executeTrans Transaction Pass 交换事务处理量(事务吞吐量) |
290 | 1449 | 3523 | |
Carte服务器平均CPU使用率 |
5.7% (Carte参数优化前为90%) |
10~30% |
85%~90% (压力过大) |
45%~70% |
Carte服务器内存使用率 |
70~80% (饱和) |
70~80% (饱和) |
70~80% (饱和) |
50%~60% |
MySql 平均CPU使用率 |
60% (MySql缓存优化前为100%) |
40% |
2% (MySql无压力) |
2% |
以上测试结果包括的具体优化过程有:Mysql开启查询缓存、Carte日志缓存时间配置、加Redes、优化Carte内存使用配置(将max_log_timeout_minutes和Object_timeout_minutes都缩小配置为1分钟)、加CPU和加内存、优化配置JVM配置调优(根据内存大小重新将spoon.sh文件中的JVM堆内存参数-Xms -Xmx优化设置)。
确认优化结果有效后(能够稳定运行15小时),再以20并发进行更长时间稳定性测试,持续压力测试到20天后出现崩溃,由于崩溃的时间点和引起崩溃原因一时难以定位,重新改变压力测试的策略(测试前开发人员再做一些优化,主要是解除和排除日志中出现的一些异常错误,如转换过程抛出的异常;并同时开启转换使用唯一连接),然后进行100并发持续压力测试(加大并发数可以实现空间换时间,缩短压测时间,以便尽快定位影响稳定性问题的原因),同时开启jvm监控,开启所有服务和数据库监控。
测试脚本日夜不间断跑测,到第二天早上看监控结果,就发现系统真的崩溃了。
一、通过Loadrunner能够看到运行13个小时后出现异常崩溃
二、通过Carte服务的CPU监控,能够看到早上7点钟前出现压力突然上升,并且无法降低
三、获取JVM监控的历史报告(JVM监控已异常断开连接),从连接时间、线程数、堆内存(无法回收内存)的变化情况,也能看出7点左右出现反常情况
四、通过监控MySQL(有两个mysql,一个是资源库,一切正常,一个是交换库出现异常),发现7点左右出现大量断开的连接
五、对交换库的监控,发现快到7点时,压力突然降低,这与上面的异常相符合
六、日志定位问题
通过上面的监控,可以判断,系统在7点前15分钟左右,应该出现故障,这就需要通过日志定位这个时段,以找到具体原因
最后在Carte服务的日志中找到答案,第一次出现连接错误的时间点是06:44:50.273,报的是Too many connections
然后错误越来越频繁,最后导致 jvm内存溢出而崩溃,
Error connecting to database: (using class org.gjt.mm.mysql.Driver)
Data source rejected establishment of connection, message from server: "Too many connections " Error...........
大量异常需要消耗效率和内存,所以之前并发数是20的时候,这个效率下降是缓慢的,现在换成100并发就很快出现问题了。所以即使carte不崩溃,转换也已经不能正常运行,因为db的瓶颈,转换中的sql脚本以及表输入或表输出等操作已经不能连接db 。
1、开启kettle转换的数据库连接池
对每个测试的转换,将其DB连接全都勾选“使用连接池” (初始大小5,最大25) 。
2、加大MySQL最大连接数,由默认100改为1000(max_connections)
再次测试,这时候压了15分钟就崩溃,通过日志查看,发现不存在数据库数异常的问题了,而且通过监控发现数据库连接正常,达到最大并发连接后没有出现中断连接
但是这次出现了新的现象,通过JVM监控发现有2千多个活动线程(正常峰值也就两百多),包括转换的线程(大部分处于监视状态)。
补充说明:关于五种状态的线程说明
运行(Running):我们最喜欢的状态。说明该线程正在执行代码,没有问题。
休眠(Sleeping):调用了Thread.sleep后的状态,说明线程正停在某个Thread.sleep处
等待(Wait):手动调用了wait方法,或者某些IO操作,在阻塞中等待数据。
驻留(Resident):常驻线程,相当于守护线程。
监视(Monitor):这里就是我想找的问题了。它表示线程想执行一段synchronized中的代码,但是发现已经有其它线程正在执行,自己被block了,只能无奈地等待。如果这种状态多,说明程序需要好好优化。
重现一下测试过程,发现到崩溃前,线程活动数突然间大量增长,如下所示:
通过threaddump分析,发现jetty 服务出现问题,有大量的线程死锁,经过开发人员的分析,是因为连接池出现大量争用,最后导致死锁,如下:
"qtp1238013097-258267 - /kettle/executeTrans/" - Thread t@258267java.lang.Thread.State: WAITINGat java.lang.Object.wait(Native Method)- waiting on <50979aad> (a java.lang.Thread)at java.lang.Thread.join(Thread.java:1245)at java.lang.Thread.join(Thread.java:1319)at org.pentaho.di.trans.Trans.prepareExecution(Trans.java:1075)at org.pentaho.di.www.ExecuteTransServlet.executeTrans(ExecuteTransServlet.java:447)at org.pentaho.di.www.ExecuteTransServlet.doGet(ExecuteTransServlet.java:354)at org.pentaho.di.www.BaseHttpServlet.doPost(BaseHttpServlet.java:103)at javax.servlet.http.HttpServlet.service(HttpServlet.java:595)at javax.servlet.http.HttpServlet.service(HttpServlet.java:668)at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:684)at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:503)at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:229)at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1086)at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:429)at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:193)at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1020)at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:135)at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:255)at org.eclipse.jetty.server.handler.HandlerList.handle(HandlerList.java:52)at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:522)at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:116)at org.eclipse.jetty.server.Server.handle(Server.java:366)at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:494)at org.eclipse.jetty.server.AbstractHttpConnection.content(AbstractHttpConnection.java:982)at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.content(AbstractHttpConnection.java:1043)at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:865)at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:240)at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:82)at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:696)at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:53)at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)at java.lang.Thread.run(Thread.java:745)Locked ownable synchronizers:- None"init of Get film categories.0 (Thread-245354)" - Thread t@258266java.lang.Thread.State: BLOCKEDat org.pentaho.di.trans.steps.databasejoin.DatabaseJoin.init(DatabaseJoin.java:216)- waiting to lock <376dc4ad> (a org.pentaho.di.trans.Trans) owned by "init of Film.0 (Thread-245334)" t@258246at org.pentaho.di.trans.step.StepInitThread.run(StepInitThread.java:69)at java.lang.Thread.run(Thread.java:745)Locked ownable synchronizers:- None"init of dim_film_actor_bridge.0 (Thread-245353)" - Thread t@258265java.lang.Thread.State: BLOCKEDat org.pentaho.di.trans.steps.insertupdate.InsertUpdate.init(InsertUpdate.java:476)- waiting to lock <376dc4ad> (a org.pentaho.di.trans.Trans) owned by "init of Film.0 (Thread-245334)" t@258246at org.pentaho.di.trans.step.StepInitThread.run(StepInitThread.java:69)at java.lang.Thread.run(Thread.java:745)Locked ownable synchronizers:- None"init of Lookup dim_actor.0 (Thread-245351)" - Thread t@258263java.lang.Thread.State: BLOCKEDat org.pentaho.di.trans.steps.databaselookup.DatabaseLookup.connectDatabase(DatabaseLookup.java:637)- waiting to lock <376dc4ad> (a org.pentaho.di.trans.Trans) owned by "init of Film.0 (Thread-245334)" t@258246at org.pentaho.di.trans.steps.databaselookup.DatabaseLookup.init(DatabaseLookup.java:577)at org.pentaho.di.trans.step.StepInitThread.run(StepInitThread.java:69)at java.lang.Thread.run(Thread.java:745)Locked ownable synchronizers:- None"init of Get film_actor.0 (Thread-245348)" - Thread t@258260java.lang.Thread.State: BLOCKEDat org.pentaho.di.trans.steps.databasejoin.DatabaseJoin.init(DatabaseJoin.java:216)- waiting to lock <376dc4ad> (a org.pentaho.di.trans.Trans) owned by "init of Film.0 (Thread-245334)" t@258246at org.pentaho.di.trans.step.StepInitThread.run(StepInitThread.java:69)at java.lang.Thread.run(Thread.java:745)Locked ownable synchronizers:- None
猜测可能是由于转换勾选了“使用唯一连接”
开发给的解释为:这个问题是由于死锁造成的,jetty线程的锁是表面现象,实际是转换步骤线程死锁,每个转换使用唯一连接的情况下,当每个转换的步骤往下进行时,不断索取连接资源。如果有时刻T刚好所有转换都在进行,并且刚好每个转换下面还有步骤需要获取连接,(这种情况不难出现),线程X占用连接B,但索要连接A, 线程Y占用连接A, 但要连接B,(可以想象多个线程是互相交叉的)就会等待对方线程释放资源,就出现死锁状态,jetty服务器于是出现阻塞。
如果转换中出现连接两个数据库时,还需要研究一下怎么才能使得资源最大化。
这个问题必须后续分析和解决(这也说明前面的优化跟最后的开启连接池优化存在冲突),这个问题留到下周来进行验证。
八、优化失败回滚部分设置
按照上周开发的解释,将转换中的“使用唯一连接”勾选去掉,再次执行100并发,这次发现不到100用户时(大概80多并发时)点击率就直线下降,到100并发时直接崩溃,性能比上周的结果还差。对比了一下使用唯一连接和不使用唯一连接的线程数分布情况如下:
图8.1 转换使用唯一连接后测试崩溃统计的线程数
图8.2 转换不使用唯一连接后测试崩溃统计的线程数
可以发现使用唯一连接后总线程要多的多(因为运行的时间比后者长),而且大部分的活动线程是被阻塞的,这与不使用唯一连接的测试结果不一样(不使用唯一连接后大部分的活动进程 处在等待中,极少部分是被阻塞,而且系统只运行了8分钟后就崩溃了,这比前者还早了7分钟,可以看出不勾选“使用唯一连接”效果更差)。
这也说明在当前配置情况下,转换中勾选唯一连接和不勾选唯一连接的结果都一样会让系统很快崩溃,实质上会有些差别(线程状态数分布不同),但这已不重要了,重要的是步骤七针对数据连接的优化是无效的,并带来了副作用,继续优化下去可能进入死胡同,因此需要进行测试回滚(回到第七步、优化数据连接),将优化数据连接的策略做一下更改,改为只加大MySQL最大连接数(设为1500),不再开启转换的连接池(完全依靠mysql自身的连接控制策略),同时保留转换使用唯一连接(好处是一个转换过程只开启一个连接,避免转换中的每个步骤都开启连接,会导致过快的消耗DB连接数)。
然后进行100并发执行测试,目前运行良好(各项指标正常,carte服务器的CPU 30%左右,内存 69%左右;交换库CPU 16%~75%,内存 21%),需要继续观察(计划运行30天)。从目前JVM运行情况来看,比较稳定:
另外我们可能也需要换个思路来提升该数据交换平台的稳定性和性能了,留待后续思考。
九、分析网络稳定性问题
经过以上有效调优后,系统运行一个晚上,发现Loadrunner还是报出了少量错误(No Route to Host):
Action.c(22): Error -27796: Failed to connect to server "172.17.2.89:8081": [10065] No Route to Host cartekettle Action 22 2017/6/3 2:21:01 3493 CarteKettle_2:310 localhost
猜测可能是跟网络延迟有关,通过优化连接数,加大Carte的连接超时时间,以及将loadrunner的超时错误时间放大,都无法避免这个错误。只能通过监控客户端与服务端的ping丢包情况(通过统制ping.vbs 脚本,以cscript ping.vbs 172.17.2.89 -t -l 1000 -w 5000>ping89.txt输出ping错误日志),结果发现真是由网络中断引起的,说明测试环境的网络是不稳定的。
说明在网络稳定性方面,需要做好重连接,这得由调用carte服务的客户端来决定,之后这块逻辑可能需要在调度上去考虑。
十、后续思考:
由于本次测试过程,已经对mysql进行了优化(加了redis缓存,提升了读写速度,减少了IO操作),同时对carte和kettle也进行了JVM配置调优,修改carte配置文件(将max_log_timeout_minutes和Object_timeout_minutes配置为最小值,及时回收内存,减少内存溢出的概率),同时对转换也进行了优化(使用唯一连接,减少转换中多步骤的DB连接资源占用)。但这些手段虽然提升了当前数据交换系统的性能和稳定性,但面对DB本身的瓶颈还是需要后续进一步的优化和性能提升。
下一步就要考虑mysql的集群化部署,包括通过mycat集群(提升mysql的高可用+读写分离)应用,并且在业务层面上,适当的开展分表分库以减轻mysql的单节点压力,具体对于mycat的配置和测试参见另一篇文章:http://blog.csdn.net/smooth00/article/details/71082046
接着就是要考虑部署Carte服务集群,进一步提升数据交换平台的高可用和高稳定性,以满足长时间的稳定运行和数据的大批量实时交换要求。
Carte+kettle+mysql性能问题定位分析记录相关推荐
- Mysql性能瓶颈深度定位分析
我们在性能测试过程中,经常会遇到Mysql出现性能瓶颈的情况,对于数据库来说,所谓的性能瓶颈无非是慢SQL.CPU高.IO高.内存高,其中前三个举实际例子来进行性能分析,最后内存高只是方法性说明(实际 ...
- 雅虎开源 MySQL 性能监控和分析器(Java)
MySQL Performance Analyzer 是雅虎公司的一个 MySQL 性能监控和分析工具,该项目包含两个子项目,分别是 Java web 应用项目 myperf 和 Java Web 服 ...
- MySQL高性能实战——part3——分析SQL,定位慢SQL(性能优化的前提)
前言: 此文借鉴<MySQL高性能>一书,还有MySQL官方文档,笔者将通过自身的一些实战经验和阅读习惯对本书进行一个总结,整理,归纳出企业级开发中常用的优化案列和部分概念!! 官方文 ...
- MySQL性能优化、故障排查及最佳实践秘籍,阿里云数据库专家玄惭的“武功”全记录...
为什么80%的码农都做不了架构师?>>> 文章简介 玄惭,真名罗龙九,阿里云DBA专家,负责阿里云RDS线上稳定以及专家服务团队.他经历过阿里历年双11实战考验,积累了7年对阿 ...
- mysql性能优化-慢查询分析、优化索引和配置
目录 一.优化概述 二.查询与索引优化分析 1性能瓶颈定位 Show命令 慢查询日志 explain分析查询 profiling分析查询 2索引及查询优化 三.配置优化 1) max_con ...
- 死磕数据库系列(三十三):MySQL 性能分析与相关工具的使用
点关注公众号,回复"1024"获取2TB学习资源! 今天我将详细的为大家介绍 MySQL 性能分析以及相关工具使用的相关知识,希望大家能够从中收获多多!如有帮助,请点在看.转发支持 ...
- 真是环境下阿里云RDS实例mysql性能优化-慢查询分析、优化索引和配置
1.实战线上数据服务器参数: 数据库类型:MySQL 5.6 : CPU:10核: 数据库内存:12000MB: 最大IOPS:100000: 最大连接数:2000: 存储空间:共200.00G,数据 ...
- MySQL性能分析工具的使用:慢查询日志、EXPLAN的使用、分析优化器执行计划:trace、MySQL监控分析视图-sys schema
文章目录 1.数据库服务器的优化步骤 2.查看系统性能参数 2.1 语法 2.2 常用参数 3.统计SQL的查询成本:last_query_cost 4.定位执行慢的SQL:慢查询日志 4.1 慢查询 ...
- mysql 性能日志_Mysql系列(十一)—— 性能分析慢查询日志
慢查询日志概念 MySQL的慢查询日志是MySQL提供的一种日志记录,它用来记录在MySQL中响应时间超过阀值的语句,具体指运行时间超过long_query_time值的SQL,则会被记录到慢查询日志 ...
- MySQL性能优化点记录
第一章 myisam,可以基于blob和text的前500字节,创建索引 myisam 支持fulltext 延迟更新索引 (delay_key_write) CREATE TABLE `table3 ...
最新文章
- 最常用的15大Eclipse开发快捷键技巧
- 域嵌套太深_pyspark如何修改嵌套结构域
- 一个页面,WEB全功能
- 差分进化算法python_差分进化算法DE-python实现
- 用juniversalchardet解决爬虫乱码问题
- 科大讯飞交通超脑荣获 2019 年大数据应用最佳实践案例 TOP10
- java 什么是内部类_讨论Java中的内部类是什么?
- 浅析Windows计算机中丢失SETUPAPI.dll的问题
- 设计模式—原型模式及其扩展(思维导图)
- 单位阶跃函数的傅里叶变换_傅里叶变换学习笔记(9)
- LayaAir WebSocket 通信
- spring boot中问题总结
- 互联网晚报 | 10月27日 星期三 | 高德车道级导航正式发布;阿里淘菜菜发布“本地菜”计划;特斯拉市值破万亿美元...
- 让画面契合音乐节拍——BeatEdit
- c语言常量要const,C语言常量-C语言const-嗨客网
- 了解“黑马程序员”有感
- android商品详情详解
- 网站被反诈中心DNS劫持解决教程
- ipad分屏功能怎么开启_iPad 重大更新!14个新功能,每个都很实用
- 近年来出现的一种新型AIE结构单元QM-β-Gal发色团-喹啉-丙二腈