天天看点

修改一行SQL代码 性能提升了100倍

事出有因

查询与计划

结果令人震惊,罪魁祸首竟然是下面这个简单的查询:

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 @&gt; 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>-&gt;  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 @&gt;</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>-&gt;  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>-&gt;  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 @&gt;</code><code>'{blah}'</code><code>::text[])</code>

<code>                    </code><code>Buffers: shared hit=</code><code>401</code>

<code>              </code><code>-&gt;  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>-&gt;  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>-&gt;  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>-&gt;  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>-&gt;  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>-&gt;  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 @&gt;</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查询速度的各种影响,