這篇blog遲到了很久,本來是想寫另一個跟網(wǎng)絡(luò)相關(guān)bug的查找過程,偷偷懶,寫下最近印象比較深刻的bug。這個bug是我的同事水寒最終定位到的。
前幾個月同事報告稱有一個線上MQ集群會同一時間拋出ArrayIndexOutOfBoundsException這個異常,也就是數(shù)組越界。查看源碼,除去一些無關(guān)緊要的細(xì)節(jié)大概是這樣子:
public class ConnectionSelector{
private AtomicInteger sets=new AtomicInteger(0);
public void selectConnection(List<Connection> connList){
if(connList==null){
return null;
}
final int size = connList.size();
if (size == 0) {
return null;
}
return connList.get(sets.incrementAndGet() % size);
}
}
private AtomicInteger sets=new AtomicInteger(0);
public void selectConnection(List<Connection> connList){
if(connList==null){
return null;
}
final int size = connList.size();
if (size == 0) {
return null;
}
return connList.get(sets.incrementAndGet() % size);
}
}
很顯然,這里的本意是實現(xiàn)一個輪詢的連接選擇器,返回一個選中的連接。使用AtomicInteger遞增并對鏈表大小取模,返回結(jié)果索引位置的連接。異常拋出的位置就是我代碼中標(biāo)紅的位置。
顯然,這里有兩種可能,一種情況下是說在執(zhí)行那一行代碼的時候,connList的大小縮小了(也就是說連接可能被其他線程移出),那么導(dǎo)致取模的結(jié)果越界。另一種可能是取模的結(jié)果本身確實超過了列表范圍。
第一種情況是完全可能的,因為服務(wù)器的連接可能隨時斷開或者重連,但是這種情況相對非常少見,因此我們這里并沒有對這個選擇過程做同步,主要是從性能的角度出發(fā),偶爾的失敗可以接受。很遺憾的是,我被我的思維慣性誤導(dǎo)了,從來沒有懷疑過第二種情況,總是認(rèn)為是不是真的連接恰巧斷開導(dǎo)致這個異常,但是卻無法解釋這個異常發(fā)生后就一直錯誤下去,無法自行恢復(fù)。
為什么說思維慣性誤導(dǎo)呢?這里的問題其實是負(fù)數(shù)取模的問題,對一個負(fù)數(shù)進(jìn)行取模,結(jié)果會是正數(shù)還是負(fù)數(shù)?答案是結(jié)果因語言而異。
我很早以前在使用Ruby的時候做過測試,負(fù)數(shù)取模結(jié)果為正數(shù),例如在irb里嘗試下:
>> -1000%3
=> 2
>> -2001%4
=> 3
=> 2
>> -2001%4
=> 3
這個印象持續(xù)至今,在clojure里結(jié)果也是這樣子:
Clojure 1.2.1
user=> (mod -1000 3)
2
user=> (mod -2001 4)
3
user=> (mod -1000 3)
2
user=> (mod -2001 4)
3
可以再試試python:
Python 2.7.1 (r271:86832, Jun 16 2011, 16:59:05)
[GCC 4.2.1 (Based on Apple Inc. build 5658) (LLVM build 2335.15.00)] on darwin
Type "help", "copyright", "credits" or "license" for more information.
>>> -10000%3
2
>>> -2001%4
3
[GCC 4.2.1 (Based on Apple Inc. build 5658) (LLVM build 2335.15.00)] on darwin
Type "help", "copyright", "credits" or "license" for more information.
>>> -10000%3
2
>>> -2001%4
3
這三種語言的結(jié)果完全一致,結(jié)果都為正數(shù)。這個慣性思維延續(xù)到j(luò)ava卻不成立了,可惜我根本沒做測試,讓我們試下:
public static void main(final String[] args) {
System.out.println(-1000 % 3);
System.out.println(-2001 % 4);
}
System.out.println(-1000 % 3);
System.out.println(-2001 % 4);
}
打印結(jié)果為:
-1
-1
-1
果然,在java里負(fù)數(shù)取模的結(jié)果為負(fù)數(shù),而不是我習(xí)慣性地認(rèn)為是正數(shù)。因此最終的定位到的原因就是sets這個變量遞增超過Integer.MAX_VALUE后越界變成負(fù)數(shù)了,取模的結(jié)果為負(fù)數(shù),導(dǎo)致拋出數(shù)組越界的異常,這也解釋了為什么同一個集群都在同一時間出問題,因為這個集群內(nèi)的機(jī)器啟動時間相鄰并且調(diào)用這個方法次數(shù)相對平均。
Update:加個abs是不夠的,因為Math.abs的javadoc提醒了:
Note that if the argument is equal to the value of Integer.MIN_VALUE, the most negative representable int value, the result is that same value, which is negative.
也就是說對Integer.MIN_VALUE做abs結(jié)果仍然是負(fù)數(shù)。盡管在這個場景中失敗一次可以接受,但是最好的辦法還是回復(fù)中steven提到的抵消符號位的做法:
(sets.incrementAndGet() & 0x7FFFFFFF) % size
這個問題更詳細(xì)的討論后來我找到這篇博客,作者討論幾種語言和計算器的這個問題的結(jié)果,給出了一些結(jié)論。不過我覺的這個結(jié)論可能也不是那么可靠,特別是對c/c++來說,很大程度上應(yīng)該還是依賴于實現(xiàn),最可靠的辦法還是強(qiáng)制結(jié)果為正。
這個bug的幾個教訓(xùn):
1、首先是第一次出現(xiàn)的時候沒有引起足夠重視,重啟解決問題后沒有深究。有句玩笑話:99%的程序問題都可以通過重啟解決。但是事實上問題仍然存在,該發(fā)生的終究還會發(fā)生。不管你信不信,它就是發(fā)生了,這是一個奇跡。
2、注意大腦的思維慣性,經(jīng)驗主義和教條主義都不可取。最近在讀一本好書《暗時間》,大腦誤導(dǎo)我們的手段可是多種多樣。
3、最后就是這個負(fù)數(shù)取模的結(jié)果因語言而異,不要依賴于特定實現(xiàn)。