解了一個怪BUG

9月 17, 2010

昨天解了一個很奇怪的BUG, 這個BUG若沒有各方的經驗, 在昨天那個moment, 水到渠成, 我想應該是誰也解不了.

問題描述是這樣子的, 某甲在用的某型號Android手機裡的Google Calendar裡某些event, 硬是跟Google web介面上的開始結束時間會早三個小時.

只有某些event會, 不是全部的event都會.
factory reset無效, 100%發生.
用敝公司前一代或後一台的Android手機都不會發生, 唯獨這一型號會.
一堆測試者都沒有回報過這個問題, 就這個某甲會. 機子也沒有特殊log.

這種bug看起來真是神奇呀, 後來處理的過程就跟癌症的幾個階段一樣, 一開始是否認它會發生, 確認後又憤怒一定要解這種鳥bug, 接來就是磋商看可不可以談掉, 談不掉就很沮喪, 最後才接受一定要解的事實.

後來這個bug引起了我的興趣, 就挑起來看一下. 我是這麼看的.

感覺會差幾個小時, 應該跟時區有關係, 先用某甲的帳號登入google calendar看看有沒有什麼時區的設定. 結果除了可以設自己所在的時區外, 並沒有找到可以設定單一event發生時間時區的地方. 這條路就斷了.
接著, 我想應該是從server抓到手機的時候, 中間應該有timezone資料, 但是手機轉錯了. 於是我就轉去看Google data api. 想寫一個小程式來看看抓回來的raw data能有什麼欄位. 研究了一下, 抓了Google Calendar API回來, 改了裡面python的sample code, dump出來某甲九月幾天有問題的event, 發生它很單純只會傳回開始時間是00:00:00.000+0800這種格式. 非常簡單, 而且最糟的是, 它是正確的(GMT+8).
後來我又很好奇, 到底在手機跟server sync的時候, 中間傳了什麼. 問了一下要怎麼抓手機上的封包, 把它從剛設好帳號到抓回來event之間的packets都存下來, 用wireshark分析一下. 發現了很多從手機連上74.125.71.101的連, 其中又有一些是單純的HTTP, 就把那一串packets存成檔案. 其中因為都已經被gzip壓過了, 看起來是亂碼. 懷著忐忑的心情用editor把前後去掉, 再用gunzip去解, 想不到居然就可以看到xml的raw data了.
再把這個XML檔丟到IE裡去看(用IE的原因是它可以把XML顯示成可以show/hide的結構), 去search有問題的event, 馬上就出現幾個關鍵字讓我很興奮起來. DTSTART;TZID=Antarctica/Casey:20100322T090000 DTEND;TZID=Antarctica/Casey. 想必這個TZID就是指Time zone id, 而Antarctica/Casey是指洲/城市. 所以這就是南極的Casey city.
立馬用google找timezone這個字, 來查查Casey的時差是多少. 然後我就查到了這裡. 裡面又看到一個很特殊的消息, 在2010/03/05前, 是GMT+11, 之後則是GMT+8. 哇! 這可真神了, 剛好差三個小時. 現在就差要怎麼證明是這個的問題了.
首先先要確定, 在別型號的手機上, server也是傳回同樣的東西, 而且仍然可以正確顯示. 所以先檢查了有問題的手機, Google calendar是用哪一版. 然後再去沒問題的那款手機, 燒一版舊的firmware, 也是用那版Google calendar的. 再抓packet來分析. 結果的確是一樣的.
在抓封包的同時, 彷彿有印象之前因為某個問題, 升級過timezone的設定. 就問了一下羅同事. 看看有問題的手機, 是用哪一版的timezone db. 看git log的結果, 它是用2009s的, 而其它型號的手機(即使是前一代的手機), 則是用2010h版.
再比較一下這兩個版本的設定, 跟Antarctica/Casey有關的設定如下
2009s

2010h
看起來就是2009s的timezone, 在2009年10月18號之後就會當做是GMT+11. 而在2010h修正了, 在2010年3月5號之後又改回GMT+8. 最後要驗證的就是把這款有問題的手機改用這個新版的timezone, 看看還有沒有問題. 最後當然是OK囉.

寫解這個BUG的過程, 是因為我覺得像這樣的bug如果沒有經驗, 看到Time zone名字就不會有直覺, 如果沒有人立刻可以問在手機上怎麼抓封包, 不知道怎麼分析封包, 不知道HTTP裡面的亂碼是GZIP壓的, 如果蘿蔔沒有先改過timezone設定, 而我又剛好知道的話. 我還真覺得這個bug是解不了的. 這種bug就是要平時累積, 然後在發生的時候水到渠成才解得掉. 不然要壓due date, 誰能壓的出來呢?