一次Zookeeper bug排查之旅 論程序員曾遇到關(guān)于性能的那些事
起因
某一天突然有同事說zk client連不上server,考慮到最近業(yè)務(wù)代碼沒有變更,懷疑是運(yùn)維同學(xué)做了什么操作導(dǎo)致,急忙聯(lián)系運(yùn)維同學(xué),確實(shí)最近做了變更。為了避免擴(kuò)大影響范圍,先讓運(yùn)維同學(xué)回滾了變更,回滾后可以正常訪問了。
復(fù)現(xiàn)問題
詢問運(yùn)維同學(xué)后,得到變更流程:由于zk集群有一臺服務(wù)器存在性能隱患,需要變更到新的一個(gè)實(shí)例。于是運(yùn)維先將新機(jī)器加入zk集群,修改舊服務(wù)器上配置逐個(gè)重啟,重啟后新zk的角色是leader,此時(shí)zk狀態(tài)正常,運(yùn)維同學(xué)也就認(rèn)為變更完成。
結(jié)果意想不到的是使用mntr命令查看,所有的機(jī)器狀態(tài)都是正常,但是zk client無法訪問,一訪問就卡住,問題可以在測試環(huán)境穩(wěn)定復(fù)現(xiàn)。
問題排查
1 猜測zk端口沒有監(jiān)聽成功,登錄服務(wù)器使用netstat查看server打開的三個(gè)端口都是正常狀態(tài),也使用了telnet測試可以連上。
2 猜測同步節(jié)點(diǎn)數(shù)不足一半,或者follower連不上leader觸發(fā)重新選舉,但很快就被排除,因?yàn)樯厦嬲f了使用mntr命令查看節(jié)點(diǎn)狀態(tài)都正常,從日志中也未能找到對應(yīng)日志記錄。
3 我們再使用stat來觀察server的連接情況,運(yùn)行zk client發(fā)現(xiàn)server收到了client的請求,但是沒有回消息,看來原因就是zk server沒處理client的請求了。
跟蹤到這里,就應(yīng)該進(jìn)入源碼了,由于對zk源碼不熟悉,咨詢了某位大佬,建議我們看zk請求處理類CommitProcessor。
在CommitProcessor我們發(fā)現(xiàn)了原因,代碼如下:
- <code>@Override
- public void start() {
- ...
- if (workerPool == null) {
- workerPool = new WorkerService("CommitProcWork", numWorkerThreads, true);
- }
- ...
- }
- public void shutdown() {
- LOG.info("Shutting down");
- halt();
- if (workerPool != null) {
- workerPool.join(workerShutdownTimeoutMS);
- }
- if (nextProcessor != null) {
- nextProcessor.shutdown();
- }
- }
- </code><button>復(fù)制</button>
在shutdown中調(diào)用了 workerPool.join實(shí)際上已經(jīng)將請求處理的開關(guān)關(guān)閉了,但是并沒有將workerPool設(shè)置為null。在start方法中會根據(jù)workerPool==null來創(chuàng)建WorkerService并開始處理請求。
修改后重新驗(yàn)證解決。