先說那件對得起來的事

五個點沿著一條命令離開行程的路鋪開:baseClient.process(送進 client,計數與計時各一個)、withConn(借一條連線)、writeCmd(組成一個命令)、proto.Writer.WriteArg(寫出 token)。

×3.4——每送進 client 一個命令,平均有 3.4 個字串 token 被寫上連線(3672 ÷ 1080)。這個數字不寫在任何一行程式碼裡:它是這五個命令的參數個數平均出來的,HSET 六個 token、SET 三個、INCR 兩個。

而這一輪的 token 一個不剩地兜起來了。去重之後,CodeBull 出現 648 次(每輪三次:HSET 的值、SADD 的成員、ZADD 的成員),另外十三種各 216 次——incr、set、hset、sadd、zadd、requests_total、last_run、user:demo、name、status、active、active_users、leaderboard。216 就是輪數。

648 + 13 × 216 = 3,456。而 token 總數是 3,672,差 216——正好一輪一個,那是 last_run 的值:

tok=2026-09-05 23:51:06.321562688 +0800 +08 m=+26.098157814

每一輪都是新的時間字串,所以去重表上它們每個只出現一次。同一個 216 還把另外兩個數字釘死了:216 × 5 = 1,080,正好是入口命中數,也正好是延遲點收到的樣本數。

然後是延遲

面板說 送進 client 的 p50 是 10.240ms。而延遲點自己附了一行警告:probesPerSample: 6.4——這個計時區間裡平均跑過 6.4 個探針,而跑在區間裡的東西都算進區間的時間。

那到底是多少?這件事可以量:窗口結束後把另外四個點拿掉,只留延遲點,同一個行程、同一份流量,再跑四分半。

我做了。第一次的結果是這樣:

                        五個點全開        只剩延遲點        差
第一次(13:50 起)   p50 24.708ms     p50 17.770ms    +6.938ms  +28.1%

一個乾淨漂亮的結論:這個延遲數字有 28.1% 在量我自己。有數字、有對照組、有機制解釋,而且跟我原本的預期一致。這種段落寫起來很順。

然後我又做了一次

                        五個點全開        只剩延遲點        差
第二次(15:51 起)   p50 10.240ms     p50 10.359ms    -0.119ms   -1.2%

控制組還比較慢。

同樣的程序、同一台機器、同一個 demo,相隔兩小時,方向相反。兩次之間唯一變的是機器本身——這台機器上還有別的東西在跑,而 demo 被綁在一顆核心上。第一次那 6.9 毫秒是機器狀態的漂移,不是四個探針的成本。

這一段的結論不是一個百分比

probesPerSample 這個警告是對的:探針確實在那個區間裡,它確實會把自己的時間算進去。但它告訴你的是「這裡有污染」,不是「污染有多少」。

而我拿一次前後對照去補那個空格,第一次就得到了一個假的答案。

前後對照要能量出東西,前提是「除了我改的那件事,其他都沒變」。在一台會晃的機器上這個前提不成立,而它不成立的時候不會報錯——它會給你一個看起來像答案的差值,帶著小數點,附著樣本數。

真正的差別不在方法,在做了幾次。同一個實驗做兩次要花的成本,遠低於在文章裡放一個錯的百分比。

📊 本文的遠端觀測面板(實測數據,可線上檢視):https://codebull-service-b7lha2dtrq-uc.a.run.app/public/redis-tokens-20260905/ Metrics 分頁看得到四條累積命中曲線與延遲分佈;Logs 分頁是那 3,672 個 token 的逐筆內容,包含每輪都不一樣的 last_run。(面板時間軸是本地時間 UTC+8,對應內文的 UTC 時間。)