從 Java 到 Python
本文為我和同事的共同研究成果
當跨語言的時候，有些東西在一門語言中很常見，但到了另一門語言中可能會很少見。
例如 C# 中，經常會關注拆箱裝箱，但到了 Java 中卻發現，根本沒人關注這個。
後來才知道，原來是因為 Java 中沒有真泛型，就算放到泛型集合中，一樣會裝箱。既然不可避免，那也就沒人去關注這塊的效能影響了。
而 C# 中要是寫出這樣的程式碼，那你明天不用來上班了。
同樣的場景發生在了學習 Python 的過程中。
什麼？資料庫連線竟然沒有連線池！？
完全不可理解啊，Java 中不用連線池對效能影響挺大的。
Python 程式設計師是因為 Python 本來就慢，然後就自暴自棄了嗎？
突然想到一個笑話
問：為什麼 Python 程式設計師很少談論記憶體洩漏?
答：因為 Python 重啟很快。
說多了都是淚，我之前排查 Java 記憶體洩漏的問題，超高併發的程式跑了1-2個月後就崩潰。我排查了好久，Java GC 引數也研究了很多，最後還是通過控制變數法找到了原因。
如果在 Python 中，多簡單的事啊，寫一個定時重啟指令碼，解決…
問題來源
那本文的問題怎麼來的呢？正是我給公司的程式碼加上連線池後產生的。一加連線池，就會有一定機率出現；一去掉連線池，就不會有。
|
1 2 3 4 5 6 7 8 |
db = get_connection() try: cursor = db.cursor() if not cursor.execute("SELECT id FROM user WHERE name = %s", ['david']) > 0: return None return cursor.fetchone()[0] finally: db.close() |
一段很簡單的程式碼，基本上整個專案中所有的資料庫查詢都是這麼寫的，本來沒任何問題。
但當我給底層加上連線池後，問題來了。
這邊後報出這樣一個異常：'NoneType' object has no attribute '__getitem__'
意思就是說cursor.fetchone() 取出來的結果是None。
但是，程式碼在呼叫之前命名已經檢查過affected rows了，根據文件cursor.execute()返回的就是affected rows。
文件也是這麼寫的：Returns long integer rows affected, if any。
解決問題第一步：網上找答案
什麼測試驅動開發，敏捷開發，我覺得都不對，一句話形容我們那應該是：基於 Google 的 Bug 驅動開發。
可惜網上無任何結果，去 stackoverflow 上問也沒人知道。
感覺又來到了一片無人區……
目前唯一能確認的就是和連線池相關了。
大致分析下應該是和連線複用有關，程式碼沒寫好？底層連線池併發處理的程式碼有 Bug？
先抓個詳細的異常看看吧。
解決問題第二步：分析異常日誌
我們專案用了 Sentry，一個異常跟蹤系統。可以把報錯時的呼叫堆疊和臨時變數都記錄下來。
第一個有用的資訊是，我們竟然發現cursor.execute()的返回結果在 Sentry 上記錄的是18446744073709552000。
這是一個非常詭異的數字，因為它接近2^64-1 (18446744073709551615)，而且還比它大了一點。
網上也找不到太多相關資料，和這個數字相關的都是 Javascript 相關的問題。
因為 Javascript 中是無法表示 2^64-1 的，相關討論：傳送門
簡單的一句話解釋就是：這個數字超過了 Javascript Integer 的最大範圍，所以底層用 Float 來表示了，所以導致丟失了精度。
但我們的程式沒用 Javascript。到了這邊，我們的第一反應一定是，要麼 MySQL 出了 Bug。要麼 MySQL-Python 出了 Bug。
解決問題第三步：一層層看原始碼分析
先看 MySQL-Python 原始碼，cursor.execute()內部呼叫了affected_rows()方法得到了這個數字，而affected_rows()這個方法內部使用 C 實現了。
MySQL-Python 的 C 部分原始碼很簡單，沒什麼邏輯：
|
1 |
return PyLong_FromUnsignedLongLong(mysql_affected_rows(&(self->connection))); |
看樣子也沒什麼特別的，這裡就兩個地方可能有問題，PyLong_FromUnsignedLongLong()和mysql_affected_rows()。
先自己嘗試寫了一段程式碼，呼叫PyLong_FromUnsignedLongLong()函式，發現無論如何都不會出現18446744073709552000這個數字。
然後看 MySQL 原始碼，mysql_affected_rows() 返回型別是my_ulonglong，原始碼中其實是這麼定義的：
|
1 |
typedef unsigned long long my_ulonglong; |
也就是說，在 C 程式碼中，這個數字最大就是2^64-1 (18446744073709551615)，不可能返回18446744073709552000的。
然後在mysql_affected_rows()的官方文件中又發現了一些有用的資訊：
An integer greater than zero indicates the number of rows affected or retrieved. Zero indicates that no records were updated for an UPDATE statement, no rows matched the WHERE clause in the query or that no query has yet been executed. -1 indicates that the query returned an error or that, for a SELECT query, mysql_affected_rows() was called prior to calling mysql_store_result().
Because mysql_affected_rows() returns an unsigned value, you can check for -1 by comparing the return value to (my_ulonglong)-1 (or to (my_ulonglong)~0, which is equivalent).
好了，遇到第一個坑了，為什麼 MySQL 官方文件說這裡可能有-1，而 MySQL-Python 的文件中卻沒說？而且返回型別是無符號的，-1就變成18446744073709551615了。
那麼如果我用if cursor.execute() > 0這種方式來判斷命中行數時，明明出錯了，我卻會得到True的結果了。
很明顯 MySQL-Python 寫的是有問題的，同事聯絡了 MySQL-Python 的作者，作者承認了這裡的問題，把程式碼修復了，下一個版本會修復。
神奇的數字
但是，看原始碼發現的東西還是沒解決我們的問題，為什麼我們的到的數字是18446744073709552000，而不是18446744073709551615？
整個呼叫鏈我們都檢查過了，不可能出現這個數字。
然後一個週末，我在快睡醒的時候突然想到了一個問題，這個數字是不是在 Python 報錯的時候，還是18446744073709551615，而到了 Sentry 中，就變成了18446744073709552000？
因為 Sentry Web 介面用的是 ajax，而 Javascript 中轉換這個數字的時候就會出錯。
最後一驗證，果然是 Sentry 的問題，Javascript 真的處處是坑。
好了，到了這一步，等 MySQL-Python 作者修復完後，我們的程式碼也就不會報錯了。問題解決？
但是，MySQL 官方卻沒有說為什麼這裡會出現-1，而且為什麼去掉了連線池就不會報錯？
就算我們的程式碼不報錯了，但如果這裡的返回數字不符合我們預期或者說不可控的話，會導致更多隱形的資料上的問題。
Root Cause
目前為止，依然沒找到 Root Cause。
別動，看好了，我要用壓測大法了！既然這個問題是在高併發使用連線池時出現的，那就壓測看看能不能重現吧。
用了同樣的程式碼，10個程式，沒有 sleep。沒想到不需要一分鐘，這個問題就會立刻重現。
而且每次重現時，都會有一些 MySQL 底層的警告，說出現了錯誤的呼叫順序。
這時，我試了一下加了一行程式碼：
|
1 2 3 4 5 6 7 8 9 10 11 |
db = get_connection() cursor = None try: cursor = db.cursor() if not cursor.execute("SELECT id FROM user WHERE name = %s", ['david']) > 0: return None return cursor.fetchone()[0] finally: if cursor: # new code cursor.close() # new code db.close() |
加完後就再也沒看到任何錯誤了。
嗯，這裡我們的程式碼寫的是不到位，我後來仔細看了官方教程，是有主動關閉cursor的程式碼的。（偷偷告訴你們，這裡都是 CTO 以前寫的 ）
粗略看了下cursor.close()的程式碼，裡面其實就是在把未讀完的資料讀完：while self.nextset(): pass。
那這裡出問題的原因也就好理解了，高併發情況下複用連線池，如果上一次請求由於某些原因沒有讀完所有資料，後面直接複用這個連線的時候，就會出現問題了。
然後，我又奇怪了，連線池框架在關閉連線的時候不應該做清理工作嗎？
Java JDBC 原始碼也看過不少了，Connection關閉的時候會清理Statement，Statement關閉的時候會清理ResultSet。因為單個連線只會在單執行緒中操作，是執行緒安全的，所以實現這樣的自動清理是非常簡單的。
以前寫 Java 中介軟體的時候，就總是把使用者當，要儘量考慮各種情況避免記憶體洩漏。我們預設都是認為使用者是從來不會去呼叫close方法的。所以常常會想方設法幫使用者去自動處理。
解決問題
最後要來解決問題了，程式碼量很大，所有呼叫都改一遍其實也不難，因為這裡都是有規律的，正則啊指令碼啊什麼的齊上陣，總是能解決的。
但是，其實也可以像 JDBC 那樣搞自動關閉。
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 |
class AutoCloseCursorConnection(object): cursor = None conn = None def __init__(self, conn): self.conn = conn def __getattr__(self, key): return getattr(self.conn, key) def cursor(self, *args, **kwargs): self.cursor = self.conn.cursor(*args, **kwargs) return self.cursor def close(self): if self.cursor: self.cursor.close() self.conn.close() |
每次建立的連線包一下，就解決問題了。