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

在開始這篇文章之前想先說一句：如果一套系統(tǒng)暫時沒問題，那只是因為它的并發(fā)量不夠而已。

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

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

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

奇怪的日志輸出

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

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

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

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

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

舊代碼分析

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

public static void oldCode（） throws IOException

{

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

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

// 明確知道的報文長度（解析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”））;}

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

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

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

上述代碼有一個明顯的錯誤，你是否能夠看出來？根據(jù)代碼原始的寫法，推測之所以出現(xiàn)這個錯誤是因為使用者對InputStream的read方法并不熟悉導(dǎo)致的。

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

InputStream的read方法

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

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

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

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

分析一下上面的三個方法。

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

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

read（b， 0， b.length）

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

Bug分析

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

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

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

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

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

while （recvLen 《 bodyLen）

{

recvLen = in.read（body， recvLen，

bodyLen - recvLen）;

if（recvLen == -1）{

break;

}}

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

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

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

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

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

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

Bug原因

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

首先，Bug之所以沒有大面積爆發(fā)，那是因為大多數(shù)請求都是一次性讀完流中的數(shù)據(jù)，循環(huán)直接結(jié)束，當不會進入第二次循環(huán)時，這個Bug就被隱藏了。

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

Bug改造

找到原因，改造起來就非常容易了。針對demo我們重新改造一下：

public static void oldCode（）

throws IOException

{

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

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

// 明確知道的報文長度（解析Header獲得）

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

System.out.println（bodyLen）;

byte［］ body = new byte［6］;

int recvLen = 0; while （recvLen 《 bodyLen）

{

// 改造點1

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

if（currentLen == -1）{

break;

}

// 改造點2

recvLen += currentLen;

}

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

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

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

小結(jié)

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

審核編輯 ：李倩