捕獲了一只發(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)?10 - 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(recvLen == -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)功能,還要滿足性能和健壯性。