天天看點

pg 函數sfa_tmp_sleep()執行越來越慢-sql分析

pg 函數sfa_tmp_sleep()執行越來越慢 

近期發現一個函數sfa_tmp_sleep()執行時間越來越長(1h32m),定時每小時執行一次(每次處理100條記錄),結果第三個都開始執行了,第一個還沒執行完~~ 

是以想要重點研究一下 

函數内容 

create or replace function sfa_tmp_sleep() 

returns text as 

$body$ 

declare 

sqlsexec character varying :=''; 

r record; 

begin 

------------------------------------------ 

----函數功能:對休眠樣本計算樣本統計資訊 

set work_mem= '3000mb'; 

sqlsexec = 'select t1.sample_hash from t_sfa_sample t1,t_white t2 where t1.sample_hash=t2.sample_hash and t1.state=-1    

and t2.sample_type=7 and not exists (select sample_hash from t_sfa_tmp where t_sfa_tmp.sample_hash=t1.sample_hash)' limit 100;                     ---這個函數隻有一條sql查詢 

raise notice '%', sqlsexec; 

for r in execute sqlsexec 

loop 

raise notice 'sample_hash = %', r.sample_hash; 

perform sfa_tmp_sample(r.sample_hash);               ---查詢出來的hash,到函數sfa_tmp_sample去進行統計打分。 

end loop; 

return 'done'; 

exception when others then 

raise exception '(%)', sqlerrm; 

return 'error'; 

end 

手動執行第一條sql,不帶limit,看耗時多久 

select t1.sample_hash from t_sfa_sample t1,t_white t2 where t1.sample_hash=t2.sample_hash and t1.state=-1 

and t2.sample_type=7 and not exists (select sample_hash from t_sfa_tmp where t_sfa_tmp.sample_hash=t1.sample_hash) ;  ---67528 ms. 

将limit條數修改成20條,看耗時多久 

測試發現,居然花了4115s,差不多一個小時,這速度簡直讓人無法忍受啊~~~~ 

我們要找出哪裡是最耗時的。 

首先,通過監控pgbadger我們可以看到函數sfa_tmp_sample,做統計其實很快,修改一條hash的統計都是毫秒級别的。 

select sfa_tmp_sample('a60cd39357f6d192547cdf85065c43d7');   單獨這樣來執行,其實很快,才500ms 

初步懷疑還是sleep中的那個查詢sql太耗時間了 

explain select t1.sample_hash from t_sfa_sample t1,t_white t2 where t1.sample_hash=t2.sample_hash 

and t2.sample_type=7  and t1.state=-1 and not exists (select sample_hash from t_sfa_tmp where t_sfa_tmp.sample_hash=t1.sample_hash) limit 1; 

"limit (cost=1.31..4.34 rows=1 width=33)" 

" -> merge join (cost=1.31..14435878.87 rows=4759688 width=33)" 

" merge cond: ((t2.sample_hash)::text = (t1.sample_hash)::text)" 

" -> merge append (cost=1.31..11326897.81 rows=19474512 width=33)" 

" sort key: t2.sample_hash" 

剛開始以為是t_white這張表太大,耗時久一點情有可原 

但我又發現一個奇怪的現象,就是手動執行的時候,帶上limit和不帶limit,時間相差很遠 

notice: select t1.sample_hash from t_sfa_sample t1,t_white t2 where t1.sample_hash=t2.sample_hash and t1.state=-1 

and t2.sample_type=7 and not exists (select sample_hash from t_sfa_tmp where t_sfa_tmp.sample_hash=t1.sample_hash) ; 

不加limit    執行select sfa_tmp_sleep() 僅僅花了81s,此時因為剛剛執行過一遍,查詢結果記錄為0,也就是不需要執行後面的select sfa_tmp_sample,按常理來說,執行完這個sql,就會立馬退出。 

and t2.sample_type=7 and not exists (select sample_hash from t_sfa_tmp where t_sfa_tmp.sample_hash=t1.sample_hash) limit 100; 

執行了很久都沒有出結果。。。。。 

為什麼加了limit反而影響了它的執行效率呢????我們來看看具體的分析結果: 

explain analyze select t1.sample_hash from t_sfa_sample t1,t_white t2 where t1.sample_hash=t2.sample_hash and t1.state=-1 

and t2.sample_type=7 and not exists (select sample_hash from t_sfa_tmp where t_sfa_tmp.sample_hash=t1.sample_hash); 

"hash join (cost=288876.92..3072363.39 rows=4764135 width=33) (actual time=74750.884..74750.884 rows=0 loops=1)"     --總耗時才74s,下面是每一步的耗時 

" hash cond: ((t2.sample_hash)::text = (t1.sample_hash)::text)" 

" -> append (cost=0.00..2589277.04 rows=19542413 width=33) (actual time=0.515..47951.685 rows=19051749 loops=1)"

" -> seq scan on t_white t2 (cost=0.00..0.00 rows=1 width=33) (actual time=0.001..0.001 rows=0 loops=1)" 

" filter: (sample_type = 7)" 

" -> bitmap heap scan on t_white20110701 t2 (cost=4.61..27.18 rows=46 width=33) (actual time=0.513..1.464 rows=43 loops=1)"     ---位圖索引,t_white每個分區表的查詢耗時都還算快。 

" recheck cond: (sample_type = 7)" 

" -> bitmap index scan on t_white20110701_sample_type_idx (cost=0.00..4.60 rows=46 width=0) (actual time=0.500..0.500 rows=53 loops=1)" 

" index cond: (sample_type = 7)" 

" -> bitmap heap scan on t_white20110801 t2 (cost=296.54..3235.54 rows=15520 width=33) (actual time=3.014..128.033 rows=15201 loops=1)" 

" -> bitmap index scan on t_white20110801_sample_type_idx (cost=0.00..292.66 rows=15520 width=0) (actual time=2.753..2.753 rows=15895 loops=1)" 

" -> seq scan on t_white20110901 t2 (cost=0.00..179.12 rows=851 width=33) (actual time=0.243..3.192 rows=828 loops=1)" 

" -> seq scan on t_white20111001 t2 (cost=0.00..33.66 rows=57 width=33) (actual time=0.243..1.555 rows=55 loops=1)"

" -> seq scan on t_white20111101 t2 (cost=0.00..26.19 rows=210 width=33) (actual time=0.290..1.000 rows=183 loops=1)" 

" -> bitmap heap scan on t_white20111201 t2 (cost=762.69..8933.83 rows=40571 width=33) (actual time=8.507..420.264 rows=40073 loops=1)" 

" -> bitmap index scan on t_white20111201_sample_type_idx (cost=0.00..752.55 rows=40571 width=0) (actual time=7.232..7.232 rows=41184 loops=1)" 

" -> seq scan on t_white20120101 t2 (cost=0.00..1534.72 rows=8484 width=33) (actual time=0.247..27.334 rows=8279 loops=1)" 

" -> seq scan on t_white20120201 t2 (cost=0.00..8966.33 rows=56440 width=33) (actual time=0.215..153.553 rows=54567 loops=1)" 

" -> seq scan on t_white20120301 t2 (cost=0.00..6881.99 rows=43735 width=33) (actual time=0.239..115.809 rows=42545 loops=1)" 

" -> bitmap heap scan on t_white20120401 t2 (cost=1000.51..11229.42 rows=53193 width=33) (actual time=10.874..426.664 rows=52150 loops=1)" 

" -> bitmap index scan on t_white20120401_sample_type_idx (cost=0.00..987.21 rows=53193 width=0) (actual time=9.207..9.207 rows=53658 loops=1)" 

" -> bitmap heap scan on t_white20120501 t2 (cost=2679.92..32892.85 rows=143434 width=33) (actual time=25.837..1573.999 rows=143011 loops=1)" 

" -> bitmap index scan on t_white20120501_sample_type_idx (cost=0.00..2644.06 rows=143434 width=0) (actual time=21.501..21.501 rows=146864 loops=1)"   --部分分區表能夠使用建立在sample_type字段的索引,是以時間明顯比沒用索引的要短 

" -> seq scan on t_white20120601 t2 (cost=0.00..16996.70 rows=98081 width=33) (actual time=0.227..359.610 rows=96404 loops=1)"     --即使沒有使用到sample_type上的索引,耗時也還能接受 

" -> seq scan on t_white20120701 t2 (cost=0.00..12755.74 rows=77482 width=33) (actual time=0.233..250.715 rows=76203 loops=1)" 

" -> seq scan on t_white20120801 t2 (cost=0.00..36999.70 rows=214737 width=33) (actual time=0.239..628.646 rows=211867 loops=1)" 

" -> seq scan on t_white20120901 t2 (cost=0.00..23962.33 rows=149082 width=33) (actual time=0.246..373.619 rows=144067 loops=1)" 

" -> seq scan on t_white20121001 t2 (cost=0.00..11539.94 rows=84231 width=33) (actual time=0.216..179.243 rows=81386 loops=1)" 

" -> seq scan on t_white20121101 t2 (cost=0.00..24504.95 rows=190559 width=33) (actual time=0.246..353.219 rows=184554 loops=1)" 

" -> seq scan on t_white20121201 t2 (cost=0.00..26269.97 rows=180864 width=33) (actual time=0.259..400.979 rows=174210 loops=1)" 

" -> seq scan on t_white20130101 t2 (cost=0.00..21436.80 rows=170187 width=33) (actual time=0.241..316.030 rows=165762 loops=1)" 

" -> seq scan on t_white20130201 t2 (cost=0.00..56572.03 rows=428164 width=33) (actual time=0.010..936.162 rows=418646 loops=1)" 

" -> seq scan on t_white20130301 t2 (cost=0.00..80714.98 rows=649873 width=33) (actual time=0.234..1272.789 rows=638643 loops=1)" 

" -> seq scan on t_white20130401 t2 (cost=0.00..48517.72 rows=385268 width=33) (actual time=0.213..729.710 rows=379044 loops=1)" 

" -> seq scan on t_white20130501 t2 (cost=0.00..43888.30 rows=359839 width=33) (actual time=0.222..690.170 rows=352550 loops=1)" 

" -> seq scan on t_white20130601 t2 (cost=0.00..46958.70 rows=364984 width=33) (actual time=0.235..785.484 rows=357265 loops=1)" 

" -> seq scan on t_white20130701 t2 (cost=0.00..59807.29 rows=362261 width=33) (actual time=0.264..929.197 rows=361180 loops=1)" 

" -> seq scan on t_white20130801 t2 (cost=0.00..80945.31 rows=599443 width=33) (actual time=0.008..1185.351 rows=582070 loops=1)" 

" -> seq scan on t_white20130901 t2 (cost=0.00..66983.62 rows=551307 width=33) (actual time=0.258..893.968 rows=536798 loops=1)" 

" -> seq scan on t_white20131001 t2 (cost=0.00..76896.57 rows=561052 width=33) (actual time=0.234..1008.501 rows=547033 loops=1)" 

" -> seq scan on t_white20131101 t2 (cost=0.00..86725.89 rows=644766 width=33) (actual time=0.216..1205.315 rows=626491 loops=1)" 

" -> seq scan on t_white20131201 t2 (cost=0.00..81994.80 rows=590138 width=33) (actual time=0.723..1646.654 rows=572707 loops=1)" 

" -> seq scan on t_white20140101 t2 (cost=0.00..74730.84 rows=471926 width=33) (actual time=0.254..1226.444 rows=462548 loops=1)" 

" -> seq scan on t_white20140201 t2 (cost=0.00..104963.35 rows=794670 width=33) (actual time=0.258..1566.819 rows=784287 loops=1)" 

" -> seq scan on t_white20140301 t2 (cost=0.00..139674.42 rows=1093780 width=33) (actual time=0.256..1892.263 rows=1077644 loops=1)" 

" -> seq scan on t_white20140401 t2 (cost=0.00..192073.55 rows=1735035 width=33) (actual time=0.215..2498.861 rows=1706597 loops=1)" 

" -> seq scan on t_white20140501 t2 (cost=0.00..156879.65 rows=1284820 width=33) (actual time=0.243..2429.547 rows=1262875 loops=1)" 

" -> seq scan on t_white20140601 t2 (cost=0.00..75085.46 rows=509768 width=33) (actual time=0.200..1142.757 rows=501259 loops=1)" 

" -> seq scan on t_white20140701 t2 (cost=0.00..109932.02 rows=801796 width=33) (actual time=0.254..1699.791 rows=785950 loops=1)" 

" -> seq scan on t_white20140801 t2 (cost=0.00..124129.98 rows=870717 width=33) (actual time=0.244..1959.016 rows=857404 loops=1)" 

" -> seq scan on t_white20140901 t2 (cost=0.00..91497.77 rows=677569 width=33) (actual time=0.208..1499.579 rows=654824 loops=1)" 

" -> seq scan on t_white20141001 t2 (cost=0.00..99435.20 rows=652200 width=33) (actual time=0.480..1943.429 rows=640646 loops=1)" 

" -> seq scan on t_white20141101 t2 (cost=0.00..80946.43 rows=629295 width=33) (actual time=0.250..1826.538 rows=597895 loops=1)" 

" -> seq scan on t_white20141201 t2 (cost=0.00..95591.54 rows=836886 width=33) (actual time=0.382..2146.592 rows=801980 loops=1)" 

" -> seq scan on t_white20150101 t2 (cost=0.00..79795.20 rows=629169 width=33) (actual time=0.022..1899.265 rows=584735 loops=1)" 

" -> seq scan on t_white20150201 t2 (cost=0.00..64520.84 rows=581339 width=33) (actual time=0.230..1430.519 rows=530069 loops=1)" 

" -> seq scan on t_white20150301 t2 (cost=0.00..83947.32 rows=660344 width=33) (actual time=0.342..2088.060 rows=653357 loops=1)" 

" -> seq scan on t_white20150401 t2 (cost=0.00..37661.30 rows=288239 width=33) (actual time=0.504..892.213 rows=285864 loops=1)"    

" -> hash (cost=277212.84..277212.84 rows=933126 width=33) (actual time=6726.655..6726.655 rows=568872 loops=1)"

" buckets: 131072 batches: 1 memory usage: 36111kb" 

" -> hash anti join (cost=147500.92..277212.84 rows=933126 width=33) (actual time=3212.152..6523.566 rows=568872 loops=1)" 

" hash cond: ((t1.sample_hash)::text = (t_sfa_tmp.sample_hash)::text)" 

" -> seq scan on t_sfa_sample t1 (cost=0.00..106786.89 rows=1861524 width=33) (actual time=0.020..1122.771 rows=1859951 loops=1)"   ---順序掃描   t_sfa_sample 中sample_hash是主鍵 

" filter: (state = (-1))"     ----過濾條件 state=-1 意味着規劃節點為它掃描的每一行檢查該條件,并且隻輸出符合條件的行 

" -> hash (cost=123638.74..123638.74 rows=1908974 width=33) (actual time=3211.371..3211.371 rows=1898083 loops=1)" 

" buckets: 262144 batches: 1 memory usage: 120484kb" 

" -> seq scan on t_sfa_tmp (cost=0.00..123638.74 rows=1908974 width=33) (actual time=0.392..2210.484 rows=1898083 loops=1)"     ---順序掃描t_sfa_tmp 表中sample_hash是主鍵 

"total runtime: 74751.386 ms" 

實際的消耗時間跟直接執行函數的時間很接近。 

explain  analyze  select t1.sample_hash from t_sfa_sample t1,t_white t2 where t1.sample_hash=t2.sample_hash and t1.state=-1 

"limit (cost=6.88..270.13 rows=100 width=33) (actual time=4208033.574..4208033.574 rows=0 loops=1)"       ---總耗時 

" -> merge join (cost=6.88..12541509.94 rows=4764141 width=33) (actual time=4208033.571..4208033.571 rows=0 loops=1)" 

" merge cond: ((t1.sample_hash)::text = (t2.sample_hash)::text)" 

" -> merge anti join (cost=5.58..1027854.50 rows=933126 width=33) (actual time=0.302..323876.834 rows=568872 loops=1)" 

" merge cond: ((t1.sample_hash)::text = (t_sfa_tmp.sample_hash)::text)" 

" -> index scan using t_sfa_sample_pkey on t_sfa_sample t1 (cost=0.00..481736.97 rows=1861524 width=33) (actual time=0.277..79479.520 rows=1859951 loops=1)" 

" filter: (state = (-1))" 

" -> index scan using t_sfa_tmp_pkey on t_sfa_tmp (cost=0.00..527407.31 rows=1908974 width=33) (actual time=0.017..229564.972 rows=1898083 loops=1)"   --跟上面的2210.484一比,雖然行數是一樣的,但是耗時确實100倍左右 

" -> materialize (cost=1.31..11414825.13 rows=19542439 width=33) (actual time=13.404..3855134.924 rows=19051765 loops=1)" 

" -> merge append (cost=1.31..11365969.04 rows=19542439 width=33) (actual time=13.397..3831856.556 rows=19051765 loops=1)" 

" -> index scan using t_white_sample_hash_key on t_white t2 (cost=0.00..8.27 rows=1 width=33) (actual time=0.005..0.005 rows=0 loops=1)"   ---所有的t_white的分區表都沒有走sample_type的索引,導緻耗時也增加了 

" -> index scan using u_t_white20110701 on t_white20110701 t2 (cost=0.00..121.13 rows=46 width=33) (actual time=0.040..31.548 rows=43 loops=1)" 

" -> index scan using u_t_white20110801 on t_white20110801 t2 (cost=0.00..13031.54 rows=15520 width=33) (actual time=1.879..3965.901 rows=15201 loops=1)" 

" -> index scan using u_t_white20110901 on t_white20110901 t2 (cost=0.00..712.33 rows=851 width=33) (actual time=0.911..199.757 rows=828 loops=1)" 

" -> index scan using u_t_white20111001 on t_white20111001 t2 (cost=0.00..140.85 rows=57 width=33) (actual time=0.046..32.823 rows=55 loops=1)" 

" -> index scan using u_t_white20111101 on t_white20111101 t2 (cost=0.00..112.66 rows=210 width=33) (actual time=0.023..57.701 rows=183 loops=1)" 

" -> index scan using u_t_white20111201 on t_white20111201 t2 (cost=0.00..34747.64 rows=40571 width=33) (actual time=1.072..4954.557 rows=40073 loops=1)" 

" -> index scan using u_t_white20120101 on t_white20120101 t2 (cost=0.00..5799.41 rows=8484 width=33) (actual time=0.024..1942.406 rows=8279 loops=1)" 

" -> index scan using u_t_white20120201 on t_white20120201 t2 (cost=0.00..35006.71 rows=56440 width=33) (actual time=0.022..11110.476 rows=54567 loops=1)" 

" -> index scan using u_t_white20120301 on t_white20120301 t2 (cost=0.00..26839.66 rows=43735 width=33) (actual time=1.412..8513.762 rows=42545 loops=1)" 

" -> index scan using u_t_white20120401 on t_white20120401 t2 (cost=0.00..43719.06 rows=53193 width=33) (actual time=0.819..11715.886 rows=52150 loops=1)" 

" -> index scan using u_t_white20120501 on t_white20120501 t2 (cost=0.00..127606.13 rows=143434 width=33) (actual time=0.309..35385.370 rows=143011 loops=1)" 

" -> index scan using u_t_white20120601 on t_white20120601 t2 (cost=0.00..66095.17 rows=98081 width=33) (actual time=0.255..19346.965 rows=96404 loops=1)" 

" -> index scan using u_t_white20120701 on t_white20120701 t2 (cost=0.00..48646.21 rows=77482 width=33) (actual time=0.031..15112.948 rows=76203 loops=1)" 

" -> index scan using u_t_white20120801 on t_white20120801 t2 (cost=0.00..140243.01 rows=214737 width=33) (actual time=0.026..40043.470 rows=211867 loops=1)" 

" -> index scan using u_t_white20120901 on t_white20120901 t2 (cost=0.00..91808.20 rows=149082 width=33) (actual time=0.764..27296.248 rows=144067 loops=1)" 

" -> index scan using u_t_white20121001 on t_white20121001 t2 (cost=0.00..45707.42 rows=84231 width=33) (actual time=0.271..17041.615 rows=81386 loops=1)" 

" -> index scan using u_t_white20121101 on t_white20121101 t2 (cost=0.00..96983.57 rows=190559 width=33) (actual time=0.220..37807.532 rows=184554 loops=1)" 

" -> index scan using u_t_white20121201 on t_white20121201 t2 (cost=0.00..103932.13 rows=180864 width=33) (actual time=0.019..39480.933 rows=174210 loops=1)" 

" -> index scan using u_t_white20130101 on t_white20130101 t2 (cost=0.00..84114.31 rows=170187 width=33) (actual time=0.238..29166.750 rows=165762 loops=1)" 

" -> index scan using u_t_white20130201 on t_white20130201 t2 (cost=0.00..223210.01 rows=428164 width=33) (actual time=0.229..82961.080 rows=418646 loops=1)" 

" -> index scan using u_t_white20130301 on t_white20130301 t2 (cost=0.00..318834.06 rows=649873 width=33) (actual time=0.225..139716.301 rows=638643 loops=1)" 

" -> index scan using u_t_white20130401 on t_white20130401 t2 (cost=0.00..191974.93 rows=385268 width=33) (actual time=0.226..80686.644 rows=379044 loops=1)" 

" -> index scan using u_t_white20130501 on t_white20130501 t2 (cost=0.00..173435.62 rows=359839 width=33) (actual time=0.239..74029.353 rows=352550 loops=1)" 

" -> index scan using u_t_white20130601 on t_white20130601 t2 (cost=0.00..185554.28 rows=364984 width=33) (actual time=0.242..75051.125 rows=357265 loops=1)" 

" -> index scan using u_t_white20130701 on t_white20130701 t2 (cost=0.00..235635.52 rows=362261 width=33) (actual time=0.634..111325.936 rows=361180 loops=1)" 

" -> index scan using u_t_white20130801 on t_white20130801 t2 (cost=0.00..319847.98 rows=599443 width=33) (actual time=0.021..137529.831 rows=582070 loops=1)" 

" -> index scan using u_t_white20130901 on t_white20130901 t2 (cost=0.00..265118.29 rows=551307 width=33) (actual time=0.199..113658.102 rows=536798 loops=1)" 

" -> index scan using u_t_white20131001 on t_white20131001 t2 (cost=0.00..304541.23 rows=561052 width=33) (actual time=0.025..115868.850 rows=547033 loops=1)" 

" -> index scan using u_t_white20131101 on t_white20131101 t2 (cost=0.00..343331.79 rows=644766 width=33) (actual time=0.309..134153.298 rows=626491 loops=1)" 

" -> index scan using u_t_white20131201 on t_white20131201 t2 (cost=0.00..324976.99 rows=590138 width=33) (actual time=0.023..125280.760 rows=572706 loops=1)" 

" -> index scan using u_t_white20140101 on t_white20140101 t2 (cost=0.00..296371.65 rows=471926 width=33) (actual time=0.244..108254.151 rows=462547 loops=1)" 

" -> index scan using u_t_white20140201 on t_white20140201 t2 (cost=0.00..412775.87 rows=794670 width=33) (actual time=0.655..154092.691 rows=784287 loops=1)" 

" -> index scan using u_t_white20140301 on t_white20140301 t2 (cost=0.00..553468.21 rows=1093780 width=33) (actual time=0.020..209569.984 rows=1077644 loops=1)" 

" -> index scan using u_t_white20140401 on t_white20140401 t2 (cost=0.00..760834.35 rows=1735035 width=33) (actual time=0.281..191973.327 rows=1706594 loops=1)" 

" -> index scan using u_t_white20140501 on t_white20140501 t2 (cost=0.00..621494.36 rows=1284820 width=33) (actual time=0.317..189809.749 rows=1262874 loops=1)" 

" -> index scan using u_t_white20140601 on t_white20140601 t2 (cost=0.00..297441.20 rows=509768 width=33) (actual time=0.028..108351.308 rows=501259 loops=1)" 

" -> index scan using u_t_white20140701 on t_white20140701 t2 (cost=0.00..435577.15 rows=801796 width=33) (actual time=0.027..156456.805 rows=785950 loops=1)" 

" -> index scan using u_t_white20140801 on t_white20140801 t2 (cost=0.00..491279.21 rows=870717 width=33) (actual time=0.154..184267.384 rows=857403 loops=1)" 

" -> index scan using u_t_white20140901 on t_white20140901 t2 (cost=0.00..362271.39 rows=677569 width=33) (actual time=0.549..134776.949 rows=654824 loops=1)" 

" -> index scan using u_t_white20141001 on t_white20141001 t2 (cost=0.00..392512.54 rows=652200 width=33) (actual time=0.025..160953.113 rows=640646 loops=1)" 

" -> index scan using u_t_white20141101 on t_white20141101 t2 (cost=0.00..320294.70 rows=629295 width=33) (actual time=0.035..115167.440 rows=597895 loops=1)" 

" -> index scan using u_t_white20141201 on t_white20141201 t2 (cost=0.00..377995.69 rows=836886 width=33) (actual time=0.024..145096.638 rows=801980 loops=1)" 

" -> index scan using u_t_white20150101 on t_white20150101 t2 (cost=0.00..314925.97 rows=629169 width=33) (actual time=0.023..95266.226 rows=584735 loops=1)" 

" -> index scan using u_t_white20150201 on t_white20150201 t2 (cost=0.00..254031.29 rows=581339 width=33) (actual time=0.027..89744.102 rows=530069 loops=1)" 

" -> index scan using u_t_white20150301 on t_white20150301 t2 (cost=0.00..336172.21 rows=660344 width=33) (actual time=0.025..109274.329 rows=653357 loops=1)" 

" -> index scan using u_t_white20150401 on t_white20150401 t2 (cost=0.00..152327.58 rows=288265 width=33) (actual time=0.031..47819.164 rows=285895 loops=1)" 

"total runtime: 4208034.397 ms"       ----跟上面一比,耗時真是的是好多倍呢~ 

總結: 

雖然一般我們使用limit,都可以以減少行數的輸出來降低時間的消耗,但是在這個例子中,我們發現,limit并不一定就能完全達到這種效果。 

一旦因為使用了limit而是執行計劃發生改變,可能會帶來緻命的損失。 

處理: 

将函數中的limit限制去掉後,我們正常去執行select sfa_tmp_sleep(),發現真的很快,僅僅隻需要60s的樣子。 

且一般情況下,一個小時内需要去統計的hash行數也不會産生很多新的。 

這也完全驗證了,之前為什麼select sfa_tmp_sample()執行都是秒級别的,一旦加了上面一個sql查詢,就必須消耗一個多小時的原因。 

再次測試: 

等sql查詢有hash需要去統計的時候,我們再來執行一次select sfa_tmp_sleep();   ----63752ms 

真的是比較快的。 

事實證明,并不是我們寫的函數有問題,而是我們在使用一些感覺會加快速度的指令時,卻無意中反而拖累了我們的函數。