一赵誓、前言

大家好傻盟，很久沒(méi)有和大家一起討論技術(shù)了活孩，那么今天我將和大家一起探討我負(fù)責(zé)的某項(xiàng)目的性能變遷之路物遇。

我們以前看到的很多架構(gòu)變遷或者演進(jìn)方面的文章大多都是針對(duì)架構(gòu)方面的介紹，很少有針對(duì)代碼級(jí)別的性能優(yōu)化介紹，這就好比蓋樓一樣询兴，樓房的基礎(chǔ)架子搭的很好乃沙，但是蓋房的工人不夠?qū)I(yè)，有很多需要注意的地方忽略了诗舰，那么在往里面填磚加瓦的時(shí)候出了問(wèn)題警儒，后果就是房子經(jīng)常漏雨，墻上有裂縫等各種問(wèn)題出現(xiàn)眶根，雖然不至于樓房塌陷蜀铲，但樓房也已經(jīng)變成了危樓。那么今天我們就將針對(duì)一些代碼細(xì)節(jié)方面的東西進(jìn)行介紹属百，歡迎大家吐槽以及提建議记劝。

**二、服務(wù)器環(huán)境 **

服務(wù)器配置：4核CPU 8G內(nèi)存 共4臺(tái)
MQ：RabbitMQ
數(shù)據(jù)庫(kù)：DB2
SOA框架：公司內(nèi)部封裝的Dubbo
緩存框架：Redis族扰，Memcached
統(tǒng)一配置管理系統(tǒng)：公司內(nèi)部開(kāi)發(fā)的系統(tǒng)

三厌丑、問(wèn)題描述

1、單臺(tái)40TPS别伏，加到4臺(tái)服務(wù)器能到60TPS蹄衷，擴(kuò)展性幾乎沒(méi)有。
2厘肮、在實(shí)際生產(chǎn)環(huán)境中愧口，經(jīng)常出現(xiàn)數(shù)據(jù)庫(kù)死鎖導(dǎo)致整個(gè)服務(wù)中斷不可用。
3类茂、數(shù)據(jù)庫(kù)事務(wù)亂用耍属，導(dǎo)致事務(wù)占用時(shí)間太長(zhǎng)。
4巩检、在實(shí)際生產(chǎn)環(huán)境中厚骗，服務(wù)器經(jīng)常出現(xiàn)內(nèi)存溢出和CPU時(shí)間被占滿。
5兢哭、程序開(kāi)發(fā)的過(guò)程中领舰，考慮不全面，容錯(cuò)很差迟螺，經(jīng)常因?yàn)橐粋€(gè)小bug而導(dǎo)致服務(wù)不可用冲秽。
6、程序中沒(méi)有打印關(guān)鍵日志矩父，或者打印了日志锉桑，信息卻是無(wú)用信息沒(méi)有任何參考價(jià)值。
7窍株、配置信息和變動(dòng)不大的信息依然會(huì)從數(shù)據(jù)庫(kù)中頻繁讀取民轴，導(dǎo)致數(shù)據(jù)庫(kù)IO很大攻柠。
8、項(xiàng)目拆分不徹底后裸，一個(gè)tomcat中會(huì)布署多個(gè)項(xiàng)目WAR包瑰钮。
9、因?yàn)榛A(chǔ)平臺(tái)的bug轻抱，或者功能缺陷導(dǎo)致程序可用性降低飞涂。
10、程序接口中沒(méi)有限流策略祈搜，導(dǎo)致很多vip商戶直接拿我們的生產(chǎn)環(huán)境進(jìn)行壓測(cè)，直接影響真正的服務(wù)可用性士八。
11容燕、沒(méi)有故障降級(jí)策略，項(xiàng)目出了問(wèn)題后解決的時(shí)間較長(zhǎng)婚度，或者直接粗暴的回滾項(xiàng)目蘸秘，但是不一定能解決問(wèn)題。
12蝗茁、沒(méi)有合適的監(jiān)控系統(tǒng)醋虏，不能準(zhǔn)實(shí)時(shí)或者提前發(fā)現(xiàn)項(xiàng)目瓶頸。

四哮翘、優(yōu)化解決方案

1颈嚼、數(shù)據(jù)庫(kù)死鎖優(yōu)化解決
我們從第二條開(kāi)始分析，先看一個(gè)基本例子展示數(shù)據(jù)庫(kù)死鎖的發(fā)生：

Paste_Image.png

分析：出現(xiàn)這種問(wèn)題就是我們?cè)陧?xiàng)目中混雜了大量的事務(wù)+for update語(yǔ)句艰匙，針對(duì)數(shù)據(jù)庫(kù)鎖來(lái)說(shuō)有下面三種基本鎖：

Paste_Image.png

當(dāng)for update語(yǔ)句和gap lock和next-key lock鎖相混合使用限煞，又沒(méi)有注意用法的時(shí)候，就非常容易出現(xiàn)死鎖的情況员凝。

那我們用大量的鎖的目的是什么署驻，經(jīng)過(guò)業(yè)務(wù)分析發(fā)現(xiàn)，其實(shí)就是為了防重健霹，同一時(shí)刻有可能會(huì)有多筆支付單發(fā)到相應(yīng)系統(tǒng)中旺上，而防重措施是通過(guò)在某條記錄上加鎖的方式來(lái)進(jìn)行。

針對(duì)以上問(wèn)題完全沒(méi)有必要使用悲觀鎖的方式來(lái)進(jìn)行防重骤公，不僅對(duì)數(shù)據(jù)庫(kù)本身造成極大的壓力抚官，同時(shí)也會(huì)把對(duì)于項(xiàng)目擴(kuò)展性來(lái)說(shuō)也是很大的擴(kuò)展瓶頸，我們采用了三種方法來(lái)解決以上問(wèn)題：

• 使用Redis來(lái)做分布式鎖阶捆，Redis采用多個(gè)來(lái)進(jìn)行分片凌节，其中一個(gè)Redis掛了也沒(méi)關(guān)系钦听，重新?tīng)?zhēng)搶就可以了。

• 使用主鍵防重方法倍奢，在方法的入口處使用防重表朴上，能夠攔截所有重復(fù)的訂單，當(dāng)重復(fù)插入時(shí)數(shù)據(jù)庫(kù)會(huì)報(bào)一個(gè)重復(fù)錯(cuò)卒煞，程序直接返回痪宰。

• 使用版本號(hào)的機(jī)制來(lái)防重。
  以上三種方式都必須要有過(guò)期時(shí)間畔裕，當(dāng)鎖定某一資源超時(shí)的時(shí)候衣撬，能夠釋放資源讓競(jìng)爭(zhēng)重新開(kāi)始。

2扮饶、數(shù)據(jù)庫(kù)事務(wù)占用時(shí)間過(guò)長(zhǎng)
偽代碼示例：

public void test() {
    Transaction.begin  //事務(wù)開(kāi)啟
    try {
        dao.insert //插入一行記錄
        httpClient.queryRemoteResult()  //請(qǐng)求訪問(wèn)
        dao.update //更新一行記錄
        Transaction.commit()  //事務(wù)提交
    } catch(Exception e) {
          Transaction.rollFor //事務(wù)回滾
    } 
}

項(xiàng)目中類似這樣的程序有很多具练，經(jīng)常把類似httpClient，或者有可能會(huì)造成長(zhǎng)時(shí)間超時(shí)的操作混在事務(wù)代碼中甜无，不僅會(huì)造成事務(wù)執(zhí)行時(shí)間超長(zhǎng)扛点，而且也會(huì)嚴(yán)重降低并發(fā)能力。

那么我們?cè)谟檬聞?wù)的時(shí)候岂丘，遵循的原則是快進(jìn)快出陵究，事務(wù)代碼要盡量小。針對(duì)以上偽代碼奥帘，我們要用httpClient這一行拆分出來(lái)铜邮，避免同事務(wù)性的代碼混在一起，這不是一個(gè)好習(xí)慣翩概。

3牲距、CPU時(shí)間被占滿分析
下面以我之前分析的一個(gè)案例作為問(wèn)題的起始點(diǎn)，首先看下面的圖：

Paste_Image.png

• 數(shù)據(jù)庫(kù)連接池影響

我們針對(duì)線上的環(huán)境進(jìn)行模擬，盡量真實(shí)的在測(cè)試環(huán)境中再現(xiàn)评姨，采用數(shù)據(jù)庫(kù)連接池為咱們默認(rèn)的C3P0难述。

那么當(dāng)壓測(cè)到二萬(wàn)批，100個(gè)用戶同時(shí)訪問(wèn)的時(shí)候吐句，并發(fā)量突然降為零胁后！報(bào)錯(cuò)如下：
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.

那么針對(duì)以上錯(cuò)誤跟蹤C(jī)3P0源碼，以及在網(wǎng)上搜索資料：
http://blog.sina.com.cn/s/blog_53923f940100g6as.html
發(fā)現(xiàn)C3P0在大并發(fā)下表現(xiàn)的性能不佳嗦枢。

• 線程池使用不當(dāng)引起

private static final ExecutorService executorService = Executors.newCachedThreadPool();
 /**
 * 異步執(zhí)行短頻快的任務(wù)
 * @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);
                }
            });

以上代碼的場(chǎng)景是每一次并發(fā)請(qǐng)求過(guò)來(lái)攀芯，都會(huì)創(chuàng)建一個(gè)線程，將DUMP日志導(dǎo)出進(jìn)行分析發(fā)現(xiàn)文虏，項(xiàng)目中啟動(dòng)了一萬(wàn)多個(gè)線程侣诺，而且每個(gè)線程都極為忙碌殖演，徹底將資源耗盡。

那么問(wèn)題到底在哪里呢年鸳？趴久？？就在這一行搔确！

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

在并發(fā)的情況下彼棍，無(wú)限制的申請(qǐng)線程資源造成性能嚴(yán)重下降，在圖表中顯拋物線形狀的元兇就是它Ｉ潘恪Ｗ丁！那么采用這種方式最大可以產(chǎn)生多少個(gè)線程呢涕蜂？坎吻？答案是：Integer的最大值！看如下源碼：

Paste_Image.png

那么嘗試修改成如下代碼：

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

修改完成以后宇葱，并發(fā)量重新上升到100以上TPS，但是當(dāng)并發(fā)量非常大的時(shí)候刊头，項(xiàng)目GC（垃圾回收能力下降）黍瞧，分析原因還是因?yàn)镋xecutors.newFixedThreadPool(50)這一行，雖然解決了產(chǎn)生無(wú)限線程的問(wèn)題原杂，但是當(dāng)并發(fā)量非常大的時(shí)候印颤，采用newFixedThreadPool這種方式，會(huì)造成大量對(duì)象堆積到隊(duì)列中無(wú)法及時(shí)消費(fèi)穿肄，看源碼如下：

Paste_Image.png

可以看到采用的是無(wú)界隊(duì)列年局，也就是說(shuō)隊(duì)列是可以無(wú)限的存放可執(zhí)行的線程，造成大量對(duì)象無(wú)法釋放和回收咸产。

• 最終線程池技術(shù)方案
  方案一：

Paste_Image.png

方案二：
使用AKKA技術(shù)框架，下面是我以前寫的一個(gè)簡(jiǎn)單的壓測(cè)情況：
http://www.reibang.com/p/6d62256e3327

4搏恤、日志打印問(wèn)題
先看下面這段日志打印程序：

QuataDTO quataDTO = null;
        try {
            quataDTO = getRiskLimit(payRequest.getQueryRiskInfo(), payRequest.getMerchantNo(), payRequest.getIndustryCatalog(), cardBinResDTO.getCardType(), cardBinResDTO.getBankCode(), bizName);
        } catch (Exception e) {
            logger.info("獲取風(fēng)控限額異常", e);
        }

像這樣的代碼是嚴(yán)格不符合規(guī)范的违寿，雖然每個(gè)公司都有自己的打印要求湃交。

• 首先日志的打印必須是以logger.error或者logger.warn的方式打印出來(lái)。
• 日志打印格式：[系統(tǒng)來(lái)源] 錯(cuò)誤描述 [關(guān)鍵信息]陨界，日志信息要能打印出能看懂的信息巡揍，有前因和后果。甚至有些方法的入?yún)⒑统鰠⒁惨紤]打印出來(lái)菌瘪。
• 在輸入錯(cuò)誤信息的時(shí)候腮敌，Exception不要以e.getMessage的方式打印出來(lái)。

合理的日志格式是：

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

logger.info("[innersys] - [入?yún) - [" + methodName + "] - "
                    + LogInfoEncryptUtil.getLogString(arguments) + "]");

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

我們?cè)诔绦蛑写罅康拇蛴∪罩厩卫m然能夠打印很多有用信息幫助我們排查問(wèn)題糜工，但是更多是日志量太多不僅影響磁盤IO，更多會(huì)造成線程阻塞對(duì)程序的性能造成較大影響录淡。
在使用Log4j1.2.14版本的時(shí)候捌木，使用如下格式：

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

那么在壓測(cè)的時(shí)候會(huì)出現(xiàn)下面大量的線程阻塞，如下圖：

Paste_Image.png

再看壓測(cè)圖如下：

Paste_Image.png

Paste_Image.png

原因可以根據(jù)log4j源碼分析如下：

Paste_Image.png

于是修改log4j配置文件為：

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

上面問(wèn)題解決彬檀，線程阻塞的情況很少出現(xiàn)帆啃，極大的提高了程序的并發(fā)能力，如下圖所示：

Paste_Image.png

未完待續(xù)窍帝，接下來(lái)將是“論代碼級(jí)性能優(yōu)化變遷之路（二）”敬請(qǐng)期待努潘！