论代码级性能优化变迁之路(一)

一、前言

大家好,很久没有和大家一起讨论技术了,那么今天我将和大家一起探讨我负责的某项目的性能变迁之路。

我们以前看到的很多架构变迁或者演进方面的文章大多都是针对架构方面的介绍,很少有针对代码级别的性能优化介绍,这就好比盖楼一样,楼房的基础架子搭的很好,但是盖房的工人不够专业,有很多需要注意的地方忽略了,那么在往里面填砖加瓦的时候出了问题,后果就是房子经常漏雨,墙上有裂缝等各种问题出现,虽然不至于楼房塌陷,但楼房也已经变成了危楼。那么今天我们就将针对一些代码细节方面的东西进行介绍,欢迎大家吐槽以及提建议。

**二、服务器环境 **

服务器配置:4核CPU 8G内存 共4台
MQ:RabbitMQ
数据库:DB2
SOA框架:公司内部封装的Dubbo
缓存框架:Redis,Memcached
统一配置管理系统:公司内部开发的系统

三、问题描述

1、单台40TPS,加到4台服务器能到60TPS,扩展性几乎没有。
2、在实际生产环境中,经常出现数据库死锁导致整个服务中断不可用。
3、数据库事务乱用,导致事务占用时间太长。
4、在实际生产环境中,服务器经常出现内存溢出和CPU时间被占满。
5、程序开发的过程中,考虑不全面,容错很差,经常因为一个小bug而导致服务不可用。
6、程序中没有打印关键日志,或者打印了日志,信息却是无用信息没有任何参考价值。
7、配置信息和变动不大的信息依然会从数据库中频繁读取,导致数据库IO很大。
8、项目拆分不彻底,一个tomcat中会布署多个项目WAR包。
9、因为基础平台的bug,或者功能缺陷导致程序可用性降低。
10、程序接口中没有限流策略,导致很多vip商户直接拿我们的生产环境进行压测,直接影响真正的服务可用性。
11、没有故障降级策略,项目出了问题后解决的时间较长,或者直接粗暴的回滚项目,但是不一定能解决问题。
12、没有合适的监控系统,不能准实时或者提前发现项目瓶颈。

四、优化解决方案

1、数据库死锁优化解决
我们从第二条开始分析,先看一个基本例子展示数据库死锁的发生:

Paste_Image.png

注:
在上述事例中,会话B会抛出死锁异常,死锁的原因就是A和B二个会话互相等待。

分析:出现这种问题就是我们在项目中混杂了大量的事务+for update语句,针对数据库锁来说有下面三种基本锁:

Paste_Image.png

当for update语句和gap lock和next-key lock锁相混合使用,又没有注意用法的时候,就非常容易出现死锁的情况。

那我们用大量的锁的目的是什么,经过业务分析发现,其实就是为了防重,同一时刻有可能会有多笔支付单发到相应系统中,而防重措施是通过在某条记录上加锁的方式来进行。

针对以上问题完全没有必要使用悲观锁的方式来进行防重,不仅对数据库本身造成极大的压力,同时也会把对于项目扩展性来说也是很大的扩展瓶颈,我们采用了三种方法来解决以上问题:

  • 使用Redis来做分布式锁,Redis采用多个来进行分片,其中一个Redis挂了也没关系,重新争抢就可以了。

  • 使用主键防重方法,在方法的入口处使用防重表,能够拦截所有重复的订单,当重复插入时数据库会报一个重复错,程序直接返回。

  • 使用版本号的机制来防重。
    以上三种方式都必须要有过期时间,当锁定某一资源超时的时候,能够释放资源让竞争重新开始。

2、数据库事务占用时间过长
伪代码示例:

public void test() {
    Transaction.begin  //事务开启
    try {
        dao.insert //插入一行记录
        httpClient.queryRemoteResult()  //请求访问
        dao.update //更新一行记录
        Transaction.commit()  //事务提交
    } catch(Exception e) {
          Transaction.rollFor //事务回滚
    } 
}

项目中类似这样的程序有很多,经常把类似httpClient,或者有可能会造成长时间超时的操作混在事务代码中,不仅会造成事务执行时间超长,而且也会严重降低并发能力。

那么我们在用事务的时候,遵循的原则是快进快出,事务代码要尽量小。针对以上伪代码,我们要用httpClient这一行拆分出来,避免同事务性的代码混在一起,这不是一个好习惯。

3、CPU时间被占满分析
下面以我之前分析的一个案例作为问题的起始点,首先看下面的图:

Paste_Image.png

项目在压测的过程中,cpu一直居高不下,那么通过分析得出如下分析:

  • 数据库连接池影响

我们针对线上的环境进行模拟,尽量真实的在测试环境中再现,采用数据库连接池为咱们默认的C3P0。

那么当压测到二万批,100个用户同时访问的时候,并发量突然降为零!报错如下:
com.yeepay.g3.utils.common.exception.YeepayRuntimeException: Could not get JDBC Connection; nested exception is java.sql.SQLException: An attempt by a client to checkout a Connection has timed out.

那么针对以上错误跟踪C3P0源码,以及在网上搜索资料:
http://blog.sina.com.cn/s/blog_53923f940100g6as.html
发现C3P0在大并发下表现的性能不佳。

  • 线程池使用不当引起
private static final ExecutorService executorService = Executors.newCachedThreadPool();
 /**
 * 异步执行短频快的任务
 * @param task
 */
 public static void asynShortTask(Runnable task){
  executorService.submit(task);
  //task.run();
 }

           CommonUtils.asynShortTask(new Runnable() {
                @Override
                public void run() {
                    String sms = sr.getSmsContent();
                    sms = sms.replaceAll(finalCode, AES.encryptToBase64(finalCode, ConstantUtils.getDB_AES_KEY()));
                    sr.setSmsContent(sms);
                    smsManageService.addSmsRecord(sr);
                }
            });

以上代码的场景是每一次并发请求过来,都会创建一个线程,将DUMP日志导出进行分析发现,项目中启动了一万多个线程,而且每个线程都极为忙碌,彻底将资源耗尽。

那么问题到底在哪里呢???就在这一行!

private static final ExecutorService executorService = Executors.newCachedThreadPool();

在并发的情况下,无限制的申请线程资源造成性能严重下降,在图表中显抛物线形状的元凶就是它!!!那么采用这种方式最大可以产生多少个线程呢??答案是:Integer的最大值!看如下源码:

Paste_Image.png

那么尝试修改成如下代码:

private static final ExecutorService executorService = Executors.newFixedThreadPool(50);

修改完成以后,并发量重新上升到100以上TPS,但是当并发量非常大的时候,项目GC(垃圾回收能力下降),分析原因还是因为Executors.newFixedThreadPool(50)这一行,虽然解决了产生无限线程的问题,但是当并发量非常大的时候,采用newFixedThreadPool这种方式,会造成大量对象堆积到队列中无法及时消费,看源码如下:

Paste_Image.png

可以看到采用的是无界队列,也就是说队列是可以无限的存放可执行的线程,造成大量对象无法释放和回收。

  • 最终线程池技术方案
    方案一:

Paste_Image.png

注:因为服务器的�CPU只有4核,有的服务器甚至只有2核,所以在应用程序中大量使用线程的话,反而会造成性能影响,针对这样的问题,我们将所有异步任务全部拆出应用项目,以任务的方式发送到专门的任务处理器处理,处理完成回调应用程序器。后端定时任务会定时扫描任务表,定时将超时未处理的异步任务再次发送到任务处理器进行处理。

方案二:
使用AKKA技术框架,下面是我以前写的一个简单的压测情况:
http://www.jianshu.com/p/6d62256e3327

4、日志打印问题
先看下面这段日志打印程序:

QuataDTO quataDTO = null;
        try {
            quataDTO = getRiskLimit(payRequest.getQueryRiskInfo(), payRequest.getMerchantNo(), payRequest.getIndustryCatalog(), cardBinResDTO.getCardType(), cardBinResDTO.getBankCode(), bizName);
        } catch (Exception e) {
            logger.info("获取风控限额异常", e);
        }

像这样的代码是严格不符合规范的,虽然每个公司都有自己的打印要求。

  • 首先日志的打印必须是以logger.error或者logger.warn的方式打印出来。
  • 日志打印格式:[系统来源] 错误描述 [关键信息],日志信息要能打印出能看懂的信息,有前因和后果。甚至有些方法的入参和出参也要考虑打印出来。
  • 在输入错误信息的时候,Exception不要以e.getMessage的方式打印出来。

合理的日志格式是:

logger.warn("[innersys] - [" + exceptionType.description + "] - [" + methodName + "] - "
                + "errorCode:[" + errorCode + "], "
                + "errorMsg:[" + errorMsg + "]", e);

logger.info("[innersys] - [入参] - [" + methodName + "] - "
                    + LogInfoEncryptUtil.getLogString(arguments) + "]");

logger.info("[innersys] - [返回结果] - [" + methodName + "] - " + LogInfoEncryptUtil.getLogString(result));

我们在程序中大量的打印日志,虽然能够打印很多有用信息帮助我们排查问题,但是更多是日志量太多不仅影响磁盘IO,更多会造成线程阻塞对程序的性能造成较大影响。
在使用Log4j1.2.14版本的时候,使用如下格式:

%d %-5p %c:%L [%t] - %m%n

那么在压测的时候会出现下面大量的线程阻塞,如下图:

Paste_Image.png

再看压测图如下:

Paste_Image.png
Paste_Image.png

原因可以根据log4j源码分析如下:

Paste_Image.png

注:Log4j源码里用了synchronized锁,然后又通过打印堆栈来获取行号,在高并发下可能就会出现上面的情况。

于是修改log4j配置文件为:

%d %-5p %c [%t] - %m%n

上面问题解决,线程阻塞的情况很少出现,极大的提高了程序的并发能力,如下图所示:

Paste_Image.png

未完待续,接下来将是“论代码级性能优化变迁之路(二)”敬请期待!

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 194,761评论 5 460
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 81,953评论 2 371
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 141,998评论 0 320
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 52,248评论 1 263
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 61,130评论 4 356
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 46,145评论 1 272
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 36,550评论 3 381
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 35,236评论 0 253
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 39,510评论 1 291
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 34,601评论 2 310
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 36,376评论 1 326
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 32,247评论 3 313
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 37,613评论 3 299
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 28,911评论 0 17
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 30,191评论 1 250
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 41,532评论 2 342
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 40,739评论 2 335

推荐阅读更多精彩内容

  • Android 自定义View的各种姿势1 Activity的显示之ViewRootImpl详解 Activity...
    passiontim阅读 171,073评论 25 707
  • 1. Java基础部分 基础部分的顺序:基本语法,类相关的语法,内部类的语法,继承相关的语法,异常的语法,线程的语...
    子非鱼_t_阅读 31,505评论 18 399
  • 分手以后最应该干的是什么呢?
    独0家7记0忆8阅读 286评论 10 1
  • 我们总是在和别人比,但其实我们最应该比的人是我们自己。当看到有人比自己优秀时,我们就想怎么才能变得和他一样优秀;当...
    罗荣阅读 395评论 4 0
  • 他人议论渺无凭,流言蜚语不足听,正义唯有天知晓,两脚端正自在行。
    动随我心阅读 201评论 0 0