丨案例為什么參數(shù)化數(shù)據(jù)會導致tps突然下降

2020-02-28 進入課20:15大小在性能測試中，參數(shù)化數(shù)據(jù)是少有的每個性能測試工程師都會用得到，卻經(jīng)常出現(xiàn)問題的技術點之一。從我的角度來說，究其原因，大部分是因為對性能參數(shù)化數(shù)據(jù)的理解不足。導致的結果就是用了參數(shù)化，但和真實的用戶場景不一致，從而使得整個性能測試場景都失去了意義。這樣的例子不在少數(shù)一個項目開始之初，由于沒有歷史沉淀的數(shù)據(jù)，所以我們需要造一些數(shù)據(jù)來做性能測試。造多少呢？并不是按未來生產(chǎn)的容量來造，而是按性能場景中需要的數(shù)據(jù)量級來造。這種錯誤的做法是很多項目中真實出現(xiàn)的事情。那么性能測試參數(shù)化數(shù)據(jù)的獲取邏輯到底是什么呢？我們來看一個圖用戶輸入的數(shù)據(jù)同時在數(shù)據(jù)庫中已存在用戶輸入的數(shù)據(jù)同時在數(shù)據(jù)庫中不存在據(jù)分布。當我們使用數(shù)據(jù)庫中不存在的數(shù)據(jù)時，就必須考慮輸入是否符合真實用戶的輸入在一次壓力測試的過程中，出現(xiàn)了如下所示的TPS數(shù)據(jù)（本篇文章中一些截圖會有在下圖中，我們可以看到，在壓力測試過程中，出現(xiàn)了TPS陡減到底的情況。這顯然是不程數(shù)降低，觀察TPS的趨勢，結果從300到100到50到10，最后到1，發(fā)現(xiàn)都會出現(xiàn)這樣的TPS陡減到底的情況，只是時間長度不同而已。首先，仍然是畫一個架構圖在這個圖中，我們可以看到，JMeter是連接到第一層服務（這里是有兩個Tomcat實例），再到第二層服務（這里是也有兩個Tomcat例），然后再連到DB。這個DB是一個互聯(lián)網(wǎng)金融DB（通過MySQL改造來的）。了解了架構圖之后，現(xiàn)在就開始查看下性能數(shù)據(jù)查操作先看一下操作系統(tǒng)的性能數(shù)從top中，我們可以看到這個應用服務器沒啥壓力，在這樣的狀態(tài)中，你可能都不用再去查應 從這個圖中可以看到的是，這個應用使用CPU實很低，并且堆也沒用多少。其實在這一步，我查了四個Tomcat的狀態(tài)，只是截了一個圖而已。應用CPU使用率（橙色CPU線）確實是太低了，才15%左右。這和前面的top也是能對得上的。JavaGC乎沒占CPU（藍色CPU），也就是說Tomcat這里沒壓從堆曲線的趨勢上來看，1G的堆才到了400M多一點，并且回收一直都非常正常。怎么判斷這個“正?！蹦?？首先，年輕代、年老代回收很有規(guī)律，并且沒消耗什么CPU；其次，每次FullGC都能回到150M左右，非常平穩(wěn)?？梢娺@個內存使用沒啥問題。當然到了這里，我當時也是查了網(wǎng)絡的，只是也沒什么壓力，所以沒做具體的記錄（從這可以看出，如果你在做性能測試的時候，要想記錄性能瓶頸的分析過程，一定要記得把數(shù)記全了，不然以后你可能都想不起來當時做了什么事情）查既然上面都沒啥問題，DB是一個MySQL，所以這里，我先手動執(zhí)行了幾個常規(guī)的查詢語句。在DB中查看如下信息。查processlist、innodb_trx、innodb_locks、innodb_lock_waits。在沒有工具時，這幾個是我經(jīng)常在MySQL數(shù)據(jù)庫檢查的表，因為數(shù)據(jù)庫如果慢的話，基本上會processlist看當然數(shù)據(jù)庫中的session并且也會把正在執(zhí)行的SQL出來，快速刷新幾次，就可以看到是不是有SQL一直卡在那里。innodb_trx是正在執(zhí)行的SQL事務表，這個表很重innodb_locks和innodb_lock_waits是為了看有沒有鎖等拿一條業(yè)務SQL執(zhí)行一下，看看在壓力之中會不會慢。這是在沒有數(shù)據(jù)庫時，快速判斷業(yè)務的方法。因為這個業(yè)務很單一，用的SQL也單一，所以我在這里可以這樣做。執(zhí)行了之后，并沒有發(fā)現(xiàn)業(yè)務SQL慢。由此基本判斷DB沒什么問題注意，判斷到了這里，其實已經(jīng)出現(xiàn)了不完整產(chǎn)生的方向偏離陷入困局之后的更悲催的是這個業(yè)務系統(tǒng)的日志記錄的非常“簡潔”，連時間消耗都沒有記錄下來。想來想去，在這么簡單的一個架構中，沒什么可查的東西了吧，除非網(wǎng)絡中有設備導致了這個問題的出現(xiàn)？在沒有其它工具的情況下，當時我們上了最傻最二最基礎又最有效的時間拆分：抓抓包其實是個挺需要技巧的活，不止是說你能把包抓出來，還要能分析出來時間消耗在誰那里。這時我提醒一下，當你學會抓包工具的使用時，不要在每個場景下都想露一手你的抓包能力，通過抓的包分析響應時間的消耗點。在我的工作中，只有萬般無奈時才會祭出“抓包”這樣的，并不是因為我對網(wǎng)絡不夠了解。恰恰是因為了解得足夠多的，我才建議不要隨便抓包。因為但凡在應用層有工具可以分析響應時間，都會比抓網(wǎng)絡層的包來得更加簡單直觀。經(jīng)過一段段的分析之后，在數(shù)據(jù)庫的一個主機上看到了如下信看到這里的TCPsegmentofareassembledPDU沒有？它之上是ACK。放大一下，看看到?jīng)]有，這里有兩秒的時間才發(fā)數(shù)據(jù)，那它是在干嗎這里就要說明一下TCPsegmentofareassembledPDU了，PDUProtocolDataUnit。以下高能燒腦，不喜可跳過它是指在TCP接收到應用層發(fā)的非常大的數(shù)據(jù)之后，需要將數(shù)據(jù)大刀闊斧地砍成幾段之后再發(fā)出去。就是這個砍數(shù)據(jù)的過程消耗了2秒的時間?？墒菫槭裁碩CP要干這個事呢？上層應用給了你一大塊數(shù)據(jù)包，你直接往外扔不就行了嗎？還要自己reassemble（重新裝配），費勁。這其實TCP的一個參數(shù)來決定的，它就是MSS（ umSegmentSize）。在TCP一開始打招呼的時候（就是握手的過程），已經(jīng)通過MSS這個可選項告訴對方自己能接收的1460字節(jié)的，為啥是1460呢？因為加上TCP頭的20個字節(jié)和IP頭的20個字節(jié)，剛好不大不小1500字節(jié)當你看到1500字節(jié)的時候，是不是有一種似曾相識的感覺？它就是現(xiàn)在普遍設 umTransmissionUnit）的大小呀這時你可能會說了，那我可以把MTU大嘛?？墒悄阕约涸O置不行呀，別人（各主機和網(wǎng)絡設備）都得跟著你設置才行，要不然到了MTU不大的地方，還得分包，還是要費時而接收端呢？接數(shù)據(jù)時接到這些包的ACK序號都是一樣的，但SequenceNumber不同，并且后一個SequenceNumber前SequenceNumber+文大小的值，那接收端就可以判斷這是一個TCPSegment了。 PDU。至于嗎？不就是過來查個數(shù)據(jù)嗎？考慮了一下業(yè)務特征，這就是根據(jù)客戶ID查一個帳戶的一個月或三個月的記錄信息，通常是100條左右，最多也就200條，也不至于有這這就是我前面說的查DB的時候，由于不全導致了分析思路的偏差。因為我手動執(zhí)行了這個語句的時候并不慢，只要10幾毫秒，所以，那時候我覺得數(shù)據(jù)庫不是問題點。但是經(jīng)過了抓包之后，發(fā)現(xiàn)問題還是出在DB上。有時候真不能那么自信呀，容易給自己挖接著分析那我們肯定要接著看DB上的信息了，既然數(shù)據(jù)量大，SQL執(zhí)行得慢，那就先撈出慢日志查看如下負載信息1#234#RankQueryResponse5#====6172839410511912131415 16<72你可以看到確實有四個SQL消耗了的時間，并且時間還不短。這是明顯的性能問題，但是我把這SQL拿出來執(zhí)行過呀，并不慢。怎么回事呢我讓做數(shù)據(jù)庫運維的人把DBproxy層的所有SQL日志拿出來分析一遍。為什么我要DBproxy層的數(shù)據(jù)呢？因為這一段會把所有執(zhí)行的SQL都記錄下來，而慢日志記錄的是1s以上的（取決于DB中的配置）。首先是把timecost大于200ms的SQL都拉出來，結果發(fā)現(xiàn)，真的在TPS下降的那個時間段，出現(xiàn)了SQL執(zhí)行超長的情況，并且和我執(zhí)行的，還是同樣的業(yè)務SQL。怎么辦？既然到這個層面了，這些執(zhí)行的SL只有一點區(qū)別，那就是查詢條件。慢的SL的查詢條件，我拿回來試了，果然是慢，查出來的數(shù)據(jù)也是完全不一樣的，居然能查出幾萬條數(shù)據(jù)來。前面說了，這個語句是根據(jù)客戶D查出記錄數(shù)的，那么就根據(jù)客戶ID，做一次roupy，看下數(shù)據(jù)量為啥有這么多大差別。于是得到了如下的結果123456789客戶ID,數(shù)'這一列只是客戶id，無它'這一列只是客戶id，無它'這一列只是客戶id，無它'這一列只是客戶id，無它'這一列只是客戶id，無它'這一列只是客戶id，無它'這一列只是客戶id，無它'這一列只是客戶id，無它'這一列只是客戶id，無它'這一列只是客戶id，無它'這一列只是客戶id，無它'這一列只是客戶id，無它'這一列只是客戶id，無它'這一列只是客戶id，無它'這一列只是客戶id，無它從這個結果可以看到，不同客戶ID的記錄條數(shù)差別太大了。這是誰干的好事？！我們一開到這里，問題基本上就明確了，查一下參數(shù)化的數(shù)據(jù)，里面有10條數(shù)據(jù)，而取到記錄數(shù)在五六萬左右的客戶ID的時候，才出現(xiàn)了響應時間長的問題。而我之前的執(zhí)行的SQL，恰好試了多次都是數(shù)據(jù)量少下面怎么辦呢？先做個最規(guī)矩的實驗，把5萬條往后的數(shù)據(jù)全都刪掉！場景再執(zhí)行一遍。問題完美解決可是問題怎么出現(xiàn)的呢經(jīng)過詢問負責產(chǎn)生基礎數(shù)據(jù)的人，最后得知，一開始數(shù)據(jù)庫里的基礎數(shù)據(jù)不夠。由于我在項目中要求基礎數(shù)據(jù)量和參數(shù)化數(shù)據(jù)量要達到生產(chǎn)級別。于是把這個工作安排給了一個同事，就是造出每個客戶都和生產(chǎn)環(huán)境中差不多量級的記錄。當時是用壓力做客戶ID的參數(shù)化，然后用執(zhí)行壓力的方式造的數(shù)據(jù)。本來這個事情在做的時候，應該是把每個客戶ID都加到差不多的記錄的。但是這個人在做之后，覺得每個客戶ID上都有了一些數(shù)據(jù)量之后，自己做了個決定，把客戶ID減少到只哭笑不得的感覺有沒有但很多時候，在真實的場景中，很多性能問題連原因都沒有分析出來，連啼笑皆非的機會都沒有，就開始尋找規(guī)避的