一只發(fā)生概率小于萬(wàn)分之一的Bug

在開(kāi)始這篇文章之前想先說(shuō)一句：如果一套系統(tǒng)暫時(shí)沒(méi)問(wèn)題，那只是因?yàn)樗牟l(fā)量不夠而已。

上周在查看系統(tǒng)日志時(shí)，發(fā)現(xiàn)了一條與眾不同的日志。日志中有一半內(nèi)容是正常的報(bào)文數(shù)據(jù)，而另一半內(nèi)容是0x00這樣的空數(shù)據(jù)。

雖然系統(tǒng)沒(méi)拋出任何異常，但這些日志肯定是反常的。多年的經(jīng)驗(yàn)告訴我，這其中一定有什么不對(duì)的地方，加上好奇心的驅(qū)使，終于揭開(kāi)了一個(gè)隱藏非常深的Bug。

有時(shí)候找到Bug，解決Bug很容易，難的是如何發(fā)現(xiàn)Bug，并推理出哪里出問(wèn)題解決。下面就帶大家來(lái)剖析一下這個(gè)Bug。

奇怪的日志輸出

一個(gè)調(diào)用外部接口的基礎(chǔ)類(lèi)，打印出類(lèi)似如下的日志：

abcdabcdabcdabcdabcdabcdabcd《0x00》《0x00》《0x00》《0x00》《0x00》

其中前面的abcd是正常的業(yè)務(wù)數(shù)據(jù)，后面莫名其妙的多出了很多《0x00》。

那么，這個(gè)基礎(chǔ)工具類(lèi)有多基礎(chǔ)？多處使用該方法，每天大約被調(diào)用幾十萬(wàn)次吧，而上面的情況一天只會(huì)出現(xiàn)幾次。就是那么巧，恰好被看到了。

查看代碼，初步推斷，可能是byte數(shù)組轉(zhuǎn)String時(shí)，byte數(shù)組后半部分為空或存在一些無(wú)法轉(zhuǎn)換的數(shù)據(jù)導(dǎo)致的。

舊代碼分析

這里先把業(yè)務(wù)代碼脫敏，寫(xiě)成一個(gè)demo展示給大家看看：

public static void oldCode（） throws IOException

{

// 通過(guò)HttpURLConnection讀取的外部系統(tǒng)返回的流

InputStream in = new ByteArrayInputStream（“abc”.getBytes（））;

// 明確知道的報(bào)文長(zhǎng)度（解析Header獲得）

int bodyLen = 2048;

byte［］ body = new byte［bodyLen］;

int recvLen = 0; while （recvLen 《 bodyLen）

{

recvLen = in.read（body， recvLen， bodyLen - recvLen）;

if（recvLen == -1）{

break;

}

}

System.out.println（new String（body， “GBK”））;}

上述代碼進(jìn)行了業(yè)務(wù)脫敏處理，僅為還原基本的使用過(guò)程。

業(yè)務(wù)場(chǎng)景的大概使用流程是：第一，通過(guò)HTTP調(diào)用遠(yuǎn)程接口；第二，讀取接口返回的字節(jié)流，Inputstream；第三，解析字節(jié)流，存入字節(jié)數(shù)組；第四，將字節(jié)數(shù)組轉(zhuǎn)換為String。

而日志中看到的異常內(nèi)容，便是打印String時(shí)出現(xiàn)的。前面我們已經(jīng)推斷，出現(xiàn)《0x00》的可能性是字節(jié)數(shù)組有一部分為空導(dǎo)致或數(shù)據(jù)錯(cuò)誤導(dǎo)致的。

上述代碼有一個(gè)明顯的錯(cuò)誤，你是否能夠看出來(lái)？根據(jù)代碼原始的寫(xiě)法，推測(cè)之所以出現(xiàn)這個(gè)錯(cuò)誤是因?yàn)槭褂谜邔?duì)InputStream的read方法并不熟悉導(dǎo)致的。

這里讀者先自行閱讀看看上述代碼的Bug在哪里，下面我們來(lái)介紹一下InputStream的read方法。

InputStream的read方法

InputStream這個(gè)抽象類(lèi)是表示字節(jié)輸入流的所有類(lèi)的超類(lèi)，它提供了3個(gè)經(jīng)常被使用的read（）方法：

read（），無(wú)參方法。該方法從輸入流中讀取數(shù)據(jù)的下一個(gè)字節(jié)。返回0到255范圍內(nèi)的int字節(jié)值。如果因?yàn)橐呀?jīng)到達(dá)流末尾而沒(méi)有可用的字節(jié)，則返回值 -1 。該方法會(huì)處于阻塞狀態(tài)，等待數(shù)據(jù)的到達(dá)，直到返回值為-1或拋出異常。

read（byte b［］， int off， int len）：將輸入流中最多l(xiāng)en個(gè)數(shù)據(jù)字節(jié)讀入byte數(shù)組。嘗試讀取len個(gè)字節(jié)，但讀取的字節(jié)也可能小于該值。以整數(shù)形式返回實(shí)際讀取的字節(jié)數(shù)。

read （byte［］ b）：從輸入流中讀取一定數(shù)量的字節(jié)，并將其存儲(chǔ)在緩沖區(qū)數(shù)組b中。以整數(shù)形式返回實(shí)際讀取的字節(jié)數(shù)。

分析一下上面的三個(gè)方法。

其中第一個(gè)方法，本質(zhì)上來(lái)說(shuō)后兩個(gè)方法都是調(diào)用第一個(gè)方法來(lái)實(shí)現(xiàn)的，但第一個(gè)方法直接使用缺點(diǎn)很明顯，就是處理效率低下，一個(gè)字節(jié)一個(gè)字節(jié)的讀。而后兩個(gè)方法都加入了byte數(shù)組，用來(lái)作為緩存區(qū)。

而第三個(gè)方法又相當(dāng)于第二個(gè)方法被如下方式調(diào)用：

read（b， 0， b.length）

而有Bug的代碼中使用的是第二個(gè)方法。

Bug分析

看了read方法的API說(shuō)明，你是不是已經(jīng)找到Bug了？對(duì)的，當(dāng)初寫(xiě)這段代碼的人把read方法返回值理解錯(cuò)了。

recvLen = in.read（body， recvLen， bodyLen - recvLen）;

最初寫(xiě)代碼的人可能把read方法的返回值當(dāng)中參數(shù)off經(jīng)過(guò)讀取之后新的位置了。這樣在調(diào)用read方法之后，獲得了填充的位置，然后拿總長(zhǎng)度減去已經(jīng)填充的位置，再繼續(xù)讀取后面的內(nèi)容，繼續(xù)填充。

但實(shí)際上read方法的返回結(jié)果是：以整數(shù)形式返回實(shí)際讀取的字節(jié)數(shù)，可能與off的位置值相同，但并不是off的位置。

下面來(lái)分析一下while循環(huán)中的邏輯處理情況：

while （recvLen 《 bodyLen）

{

recvLen = in.read（body， recvLen，

bodyLen - recvLen）;

if（recvLen == -1）{

break;

}}

我們舉個(gè)例子來(lái)推演一下2種情況（為了方便推算，暫且用比較小的數(shù)來(lái)舉例）。

情況一：假設(shè)bodyLen長(zhǎng)度為10，read一次性讀完。

在這種情況中，先進(jìn)入while循環(huán)，read一次性讀完，返回值為10，此時(shí)recvLen賦值為10，不再滿足循環(huán)條件（recvLen 《 bodyLen），退出循環(huán)，繼續(xù)執(zhí)行。此時(shí)，代碼沒(méi)問(wèn)題。這種情況可能占到99.9%-99.99%（取決于請(qǐng)求頻次和報(bào)文大?。?。

情況二：假設(shè)bodyLen長(zhǎng)度為10，read 2次讀完（發(fā)生粘包拆包現(xiàn)象）。

第一次循環(huán)，read讀取6個(gè)字節(jié)長(zhǎng)度，返回值為6，recvLen賦值為6。第二次循環(huán)，off參數(shù)取recvLen的值為6，讀取剩余4個(gè)字節(jié)（10 - 6）。完成第二次讀取，循環(huán)本應(yīng)該結(jié)束的，但你會(huì)發(fā)現(xiàn)此時(shí)recvLen被賦值為4，依舊滿足while循環(huán)的判斷條件（recvLen 《 bodyLen），進(jìn)行下一輪讀取。

下一輪讀取時(shí)，off變?yōu)?，len變?yōu)椋?0 - 4）。本來(lái)經(jīng)過(guò)第二輪循環(huán)off已經(jīng)讀取到10了，現(xiàn)在又指定為4，又去流中讀取。這就造成了日志中出現(xiàn)很多《0x00》。

Bug原因

經(jīng)過(guò)上述分析，我們已經(jīng)找到Bug，并獲得了Bug原因。

首先，Bug之所以沒(méi)有大面積爆發(fā)，那是因?yàn)榇蠖鄶?shù)請(qǐng)求都是一次性讀完流中的數(shù)據(jù)，循環(huán)直接結(jié)束，當(dāng)不會(huì)進(jìn)入第二次循環(huán)時(shí)，這個(gè)Bug就被隱藏了。

其次，Bug之所以發(fā)生除了使用者對(duì)API的返回值不了解，更重要的原因是對(duì)于read方法可能會(huì)將結(jié)果分多次返回（粘包拆包現(xiàn)象）不了解。

Bug改造

找到原因，改造起來(lái)就非常容易了。針對(duì)demo我們重新改造一下：

public static void oldCode（）

throws IOException

{

// 通過(guò)HttpURLConnection讀取的外部系統(tǒng)返回的流

InputStream in = new ByteArrayInputStream（“abc”.getBytes（））;

// 明確知道的報(bào)文長(zhǎng)度（解析Header獲得）

int bodyLen = “abc”.getBytes（）.length;

System.out.println（bodyLen）;

byte［］ body = new byte［6］;

int recvLen = 0; while （recvLen 《 bodyLen）

{

// 改造點(diǎn)1

int currentLen = in.read（body， recvLen， bodyLen - recvLen）;

if（currentLen == -1）{

break;

}

// 改造點(diǎn)2

recvLen += currentLen;

}

System.out.println（new String（body， “GBK”））;}

上述改造只改動(dòng)了兩處，將read方法的返回值用新變量接收，然后讓recvLen每次累加read讀取的字節(jié)數(shù)。

改造是不是非常簡(jiǎn)單？正應(yīng)了那句話：改bug很容易，難的是如何找到bug。

小結(jié)

有時(shí)候我們對(duì)自己寫(xiě)的代碼很自信，有時(shí)候總以為代碼之前能夠正常運(yùn)行，以后也能夠正常運(yùn)行。但往往事與愿違，誰(shuí)能想到一直“運(yùn)行良好”的代碼中深藏著這樣的Bug？所以，還是那句話，如果你覺(jué)得你的代碼沒(méi)問(wèn)題，那只是因?yàn)橄到y(tǒng)的并發(fā)量還不夠而已。代碼不僅要實(shí)現(xiàn)功能，還要滿足性能和健壯性。

審核編輯 ：李倩