事出有因
查詢與計劃
結果令人震驚,罪魁禍首竟然是下面這個簡單的查詢:
1
2
3
4
5
6
7
8
9
10
<code>SELECT c.key,</code>
<code> </code><code>c.x_key,</code>
<code> </code><code>c.tags,</code>
<code> </code><code>x.name</code>
<code> </code><code>FROM context c</code>
<code> </code><code>JOIN x</code>
<code> </code><code>ON c.x_key = x.key</code>
<code>WHERE c.key = ANY (ARRAY[</code><code>15368196</code><code>, --</code><code>11</code><code>,</code><code>000</code>
<code>other keys --)])</code>
<code> </code><code>AND c.x_key =</code><code>1</code>
<code> </code><code>AND c.tags @> ARRAY[E</code><code>'blah'</code><code>];</code>
X表擁有上千行資料,C表擁有1500萬行資料,這兩個表的“key”列都帶有适當的索引主鍵。簡單地說,它就是一個簡單的主鍵查詢。但有趣地是,随着key列中記錄的增加,例如在11000行時,我們通過添加EXPLAIN (ANALYZE, BUFFERS)字首來檢視key列的值是否與數組中的值比對:
11
12
13
14
15
16
17
18
<code>Nested Loop (cost=</code><code>6923.33</code><code>..</code><code>11770.59</code>
<code>rows=</code><code>1</code> <code>width=</code><code>362</code><code>) (actual time=</code><code>17128.188</code><code>..</code><code>22109.283</code>
<code>rows=</code><code>10858</code> <code>loops=</code><code>1</code><code>)</code>
<code> </code><code>Buffers: shared hit=</code><code>83494</code>
<code> </code><code>-> Bitmap Heap Scan on context c (cost=</code><code>6923.33</code><code>..</code><code>11762.31</code>
<code>rows=</code><code>1</code> <code>width=</code><code>329</code><code>) (actual time=</code><code>17128.121</code><code>..</code><code>22031.783</code>
<code> </code><code>Recheck Cond: ((tags @></code><code>'{blah}'</code><code>::text[]) AND (x_key =</code><code>1</code><code>))</code>
<code> </code><code>Filter: (key = ANY (</code><code>'{15368196,(a lot more keys here)}'</code><code>::integer[]))</code>
<code> </code><code>Buffers: shared hit=</code><code>50919</code>
<code> </code><code>-> BitmapAnd (cost=</code><code>6923.33</code><code>..</code><code>6923.33</code>
<code>rows=</code><code>269</code> <code>width=</code><code>0</code><code>) (actual time=</code><code>132.910</code><code>..</code><code>132.910</code>
<code>rows=</code><code>0</code> <code>loops=</code><code>1</code><code>)</code>
<code> </code><code>Buffers: shared hit=</code><code>1342</code>
<code> </code><code>-> Bitmap Index Scan on context_tags_idx (cost=</code><code>0.00</code><code>..</code><code>1149.61</code>
<code>rows=</code><code>15891</code> <code>width=</code><code>0</code><code>) (actual time=</code><code>64.614</code><code>..</code><code>64.614</code>
<code>rows=</code><code>264777</code> <code>loops=</code><code>1</code><code>)</code>
<code> </code><code>Index Cond: (tags @></code><code>'{blah}'</code><code>::text[])</code>
<code> </code><code>Buffers: shared hit=</code><code>401</code>
<code> </code><code>-> Bitmap Index Scan on context_x_id_source_type_id_idx (cost=</code><code>0.00</code><code>..</code><code>5773.47</code>
<code>rows=</code><code>268667</code> <code>width=</code><code>0</code><code>) (actual time=</code><code>54.648</code><code>..</code><code>54.648</code>
<code>rows=</code><code>267659</code> <code>loops=</code><code>1</code><code>)</code>
<code> </code><code>Index Cond: (x_id =</code><code>1</code><code>)</code>
<code> </code><code>Buffers: shared hit=</code><code>941</code>
<code> </code><code>-> Index Scan using x_pkey on x (cost=</code><code>0.00</code><code>..</code><code>8.27</code>
<code>rows=</code><code>1</code> <code>width=</code><code>37</code><code>) (actual time=</code><code>0.003</code><code>..</code><code>0.004</code>
<code>rows=</code><code>1</code> <code>loops=</code><code>10858</code><code>)</code>
<code> </code><code>Index Cond: (x.key =</code><code>1</code><code>)</code>
<code> </code><code>Buffers: shared hit=</code><code>32575</code>
<code>Total runtime:</code>
<code>22117.417</code> <code>ms</code>
這次查詢共花費22s,我們可以通過下圖對這22s進行很直覺的了解,其中大部分時間花費在Postgres和OS之間,而磁盤I/O則花費非常少的時間。
在最低水準,這些查詢看起來就像是這些CPU使用率的峰值。在這裡主要是想證明一個關鍵點:資料庫不會等待磁盤去讀取資料,而是做排序、散列和行比較這些事。
通過Postgres擷取與峰值最接近的行數。
顯然,我們的查詢在大多數情況下都有條不紊的執行着。
Postgres的性能問題:位圖堆掃描
rows_fetched度量與下面的部分計劃是一緻的:
<code>Buffers: shared hit=</code><code>83494</code>
幸運的是,我們的表有30%都是裝載在RAM中,是以在從磁盤上檢查行的時候,它不會表現的太糟糕。但在性能上,它仍然存在非常明顯的影響。查詢過于簡單,這是一個非常簡單的key查找,是以沒有顯而易見的資料庫或應用重構,它很難找到一些簡單的方式來解決這個問題。最後,我們使用
解決方案
<code>WHERE c.key = ANY (VALUES (</code><code>15368196</code><code>), --</code><code>11</code><code>,</code><code>000</code>
<code>other keys --)</code>
你能發現有啥不同之處嗎?把ARRAY換成了VALUES。
我們使用ARRAY[...]列舉出所有的關鍵字來進行查詢,但卻欺騙了查詢優化器。Values(...)讓優化器充分使用關鍵字索引。僅僅是一行代碼的改變,并且沒有産生任何語義的改變。
下面是新查詢語句的寫法,差别就在于第三和第十四行。
<code>Nested Loop (cost=</code><code>168.22</code><code>..</code><code>2116.29</code>
<code>rows=</code><code>148</code> <code>width=</code><code>362</code><code>) (actual time=</code><code>22.134</code><code>..</code><code>256.531</code>
<code> </code><code>Buffers: shared hit=</code><code>44967</code>
<code>rows=</code><code>1</code> <code>width=</code><code>37</code><code>) (actual time=</code><code>0.071</code><code>..</code><code>0.073</code>
<code>rows=</code><code>1</code> <code>loops=</code><code>1</code><code>)</code>
<code> </code><code>Index Cond: (id =</code><code>1</code><code>)</code>
<code> </code><code>Buffers: shared hit=</code><code>4</code>
<code> </code><code>-> Nested Loop (cost=</code><code>168.22</code><code>..</code><code>2106.54</code>
<code>rows=</code><code>148</code> <code>width=</code><code>329</code><code>) (actual time=</code><code>22.060</code><code>..</code><code>242.406</code>
<code> </code><code>Buffers: shared hit=</code><code>44963</code>
<code> </code><code>-> HashAggregate (cost=</code><code>168.22</code><code>..</code><code>170.22</code>
<code>rows=</code><code>200</code> <code>width=</code><code>4</code><code>) (actual time=</code><code>21.529</code><code>..</code><code>32.820</code>
<code>rows=</code><code>11215</code> <code>loops=</code><code>1</code><code>)</code>
<code> </code><code>-> Values Scan on</code><code>"*VALUES*"</code> <code>(cost=</code><code>0.00</code><code>..</code><code>140.19</code>
<code>rows=</code><code>11215</code> <code>width=</code><code>4</code><code>) (actual time=</code><code>0.005</code><code>..</code><code>9.527</code>
<code> </code><code>-> Index Scan using context_pkey on context c (cost=</code><code>0.00</code><code>..</code><code>9.67</code>
<code>rows=</code><code>1</code> <code>width=</code><code>329</code><code>) (actual time=</code><code>0.015</code><code>..</code><code>0.016</code>
<code>rows=</code><code>1</code> <code>loops=</code><code>11215</code><code>)</code>
<code> </code><code>Index Cond: (c.key =</code><code>"*VALUES*"</code><code>.column1)</code>
<code> </code><code>Filter: ((c.tags @></code><code>'{blah}'</code><code>::text[]) AND (c.x_id =</code><code>1</code><code>))</code>
<code> </code><code>Buffers: shared hit=</code><code>44963</code>
<code>263.639</code> <code>ms</code>
從22000ms到200ms,僅僅修改了一行代碼,速度提升了100倍還多。
産品裡新的查詢
部署後的代碼:
資料庫看起來更美觀
Postgres慢查詢将一去不複返了。但有誰願意因為這個0.1%的倒黴蛋再去折磨呢?我們使用Datadog來驗證修改是否正确,它能夠做出即時驗證。如果你想檢視Postgres查詢速度的各種影響,