先決定要站在哪裡看
singleflight 大概是 Go 裡最常被推薦的小工具:好幾個人同時要同一份資料,只讓一個人真的去查,其他人等著拿同一份結果,就一行 group.Do(key, fn)。我一直把它理解成「幫我省掉重複的查詢」。
被觀測的是一支小服務:讀者輪流要三個熱門 key,每次讀取都經過同一個 Group,後面是一個假資料庫——每次查詢睡 100–120 毫秒,每第十次查詢固定逾時。沒有快取。前四分鐘一個讀者,後六分鐘八個讀者做一模一樣的事;那四分鐘是對照組。
站在讀者那層,只看得到「我拿到了什麼」;站在資料庫那層,只看得到「被查了幾次」。只有中間的 Group.Do 知道誰跟誰拿的是同一份,所以點掛在三層:serve 呼叫 Do 的那一行(讀者發出請求)、Do 裡的 c.wg.Wait()(排隊等別人的結果)、自己去查的人要 return 的第 114 行(查完分給幾人,抓 c.dups 與整個 c)、loadRow(查資料庫,抓 n={n} fail={fail} 加上耗時)、以及 serve 拿到回傳之後(讀者拿到結果)。
c.dups 是 singleflight 手上的一個整數:這次查詢跑完時,後面排了幾個人。那如果這次查詢逾時了,後面那幾個人拿到的是什麼?
前四分鐘:一個讀者
窗口是 2026-09-24 14:01:57Z 到 14:11:57Z。前四分鐘 577 次讀取、577 次查詢,dups 全部是 0;58 次查詢逾時,58 個讀者拿到逾時。沒有人可以共用,singleflight 什麼都沒做。
後六分鐘,圖上那兩條邊開始分岔:4,478 ÷ 7,602 = ×0.59 的讀取是去排隊,3,124 ÷ 7,602 = ×0.41 是自己去查,兩條加起來是 1——不是排隊,就是自己查。把時間軸拖到 A 段,排隊等別人的結果 是零。
窗口最後一秒
八個讀者那六分鐘,dups 不再只有 0:
dups(後面排了幾個人) 成功的查詢 逾時的查詢
0 392 45
1 635 75
2 667 74
3 375 37
4 172 17
5 49 5
6 3 1
我在面板的 Logs 分頁拉到窗口最後一秒,看到這幾行(節錄,拿掉了節點標籤;面板時間是 UTC+8):
[22:11:56.220] main.loadRow:67 n=3430 fail=true
[22:11:56.330] singleflight.(*Group).Do:114 dups=1
[22:11:56.330] main.serve:87 key=user:1 outcome=db: query timeout shared=true
[22:11:56.331] main.serve:87 key=user:1 outcome=db: query timeout shared=true
第 3,430 次查詢註定逾時。110 毫秒後它 return,兩個讀者在一毫秒之內拿到同一個逾時,其中一個從頭到尾沒碰過資料庫。我回頭看那個點抓到的整個 c:312 次逾時,c.err 全部是同一行,*errors.errorString(data: 0x180cff1f100)。
同一個位址。 不是每個人各收到一個逾時,是同一個 error 值被交到每個排隊的人手上。六分鐘加起來,254 次逾時的查詢打到 687 個讀者,平均每次 2.705 人;2,293 次成功的查詢交出 6,338 份資料,平均每次 2.764 人。687 = 45 + 75×2 + 74×3 + 37×4 + 17×5 + 5×6 + 1×7。失敗被分出去的倍數,跟成功幾乎一樣。 表格最下面那個 1,就是一次逾時一口氣發給了七個人。
我以為 singleflight 省掉的是重複的查詢。現在我知道,它做的是分發同一份結果——不管好壞,就是當下排在那個 key 後面所有人的結果。
誠實說
失敗率沒有變。 後六分鐘查詢的逾時比例是 254 ÷ 2,547 = 9.97%,讀者是 687 ÷ 7,025 = 9.78%。singleflight 沒讓讀者更常失敗,它改變的是失敗的形狀:從一次一個人,變成一次一群人。而 10% 是我寫死的,不是發現。
shared=true 不代表「我沒查」。 讀者端有 6,588 次 shared=true,真正排隊的只有 4,478 次;差額 2,110 正好是「自己去查、後面也有人排」的次數。照字面把它讀成「共用的讀取」會多算。
圖上兩個孤立的節點。 讀者拿到結果 和 讀者發出請求 在同一個函式裡,一個在呼叫 Do 之前、一個在它回來之後,彼此不在對方的堆疊上,所以它是自己的 root,不是子節點。查資料庫 則是因為它的計時點拿不到堆疊,圖不替它畫入邊;它真正的路徑 Do → doCall → serve.func1 → loadRow 中間那幾層我沒有掛點。另外,觀測工具自己回的那份圖用函式名比對堆疊,把同一個函式裡的點接成了父子,多出幾條不可能存在的邊;這張圖改用函式加行號重建,跟面板上畫的一致。
看不到的: 排隊的人各等了多久我沒量;110.816 毫秒的 p50 是查詢本身,包含第 67 行那個點。
對帳。 這一輪不回報掉包,所以我用服務自己的計數器:窗口內 failed-loads 從 31 到 343、failed-reads 從 81 到 826,差額 312 與 745,跟觀測點的 58 + 254、58 + 687 一分不差。那個計數器只給總量——826 看不出是各自倒楣,還是某幾次一次打七個。
結果
我現在知道,在 singleflight 後面,一次逾時的影響範圍不是一個請求,而是那一刻排在同一個 key 後面的所有人。我的服務裡最多七個;一個逾時設五秒、熱鍵每秒被要幾百次的服務會是多少,我不知道——但那個數字就在 c.dups 裡,每一次都有。
📊 本文的遠端觀測面板(實測數據,可線上檢視):https://codebull-service-b7lha2dtrq-uc.a.run.app/public/singleflight-demo-article-20260922/ Behavior Graph 分頁是文章開頭那張圖的面板版,Logs 分頁 22:11:56 那幾行可以逐字對帳。(面板時間軸是本地時間 UTC+8,對應內文的 UTC 窗口。)
這一輪對被觀測服務做了什麼:main.go 加了一行 blank import 把 SDK 帶進二進位檔,並用 -gcflags="all=-dwarflocationlists=true -N -l" 編譯。業務邏輯一個字沒動,沒有加任何 log 或計數器(服務每 10 秒印的那行計數是 demo 本來就有的對帳來源)。六個觀測點全部是行程跑起來之後才掛上去的:main.serve:80、singleflight.(*Group).Do:99、Do:114、main.loadRow:67 加上 loadRow:66–68 的計時、main.serve:87。查詢耗時 p50 110.816 / p95 119.895 / p99 121.036 / 最大 125.221 毫秒。這一輪沒量排隊者的等待時間;逾時是固定每十次一次,不是真實分佈。