Performance

Postgres 10 查詢等待 IO：BufFileWrite 導致無法獲取新的數據庫連接

  • March 12, 2021

我有一個查詢（附有查詢計劃），每 5-7 秒從執行我們儀表板的每個設備（通常在高峰時間有 500 多個設備）執行一次。該查詢一開始看起來像是在等待狀態中花費時間IO:BufFileWrite。

從 AWS Aurora Performance Insights 儀表板中，可以看到有問題的查詢在IO: BUfFileWrite等待狀態下花費了更多時間（圖中的天藍色）

Performance_Insights

Postgres 配置/詳細資訊：

  1. AWS 極光 PostgreSQL 10.6
  2. R5.4X 大型實例（128 GB RAM）
  3. work_mem = 80MB
  4. 我使用 hikari 連接池來管理數據庫連接。

一周前，我開始在我的應用伺服器上看到許多錯誤：

Failed to get database connection errors

和/或

java.sql.SQLTimeoutException: Timeout after 30000ms of waiting for a connection

在 PGAdmin 的幫助下進行了一些調試，發現大多數連接都在等待IO: BufFileWrite，因此意識到預設的4MB work_mem不足以進行查詢。

PGAdmin 統計

在 PgBadger 的幫助下，看到平均臨時文件大小為 70MB，因此將其更新work_mem為 80 MB。

Temp_File_Pg_Badger

這絕對有幫助，我開始看到較少的數據庫連接問題，但它並沒有完全消失。

我使用Postgres Visualize Analyzer和Explain Depesz來了解查詢計劃，發現僅索引掃描的**總成本為 4984972.45，計劃行數為 111195272。**此表 ( students_points) 實際上有 100M+ 行，大小約為 15GB，並且未分區。

我嘗試添加部分索引 ( create index students_latest_point_idx ON students_points (student_id, evaluation_date desc))，希望上述掃描的成本會提高，但徒勞無功。

我已經在所涉及的表上執行，但沒有明顯的性能改進VACUUM ( FULL, ANALYZE, VERBOSE);。REINDEX

我需要以下幫助

  1. never executed查詢計劃的部分是什麼意思？- 我檢查了網上的文獻，但除了 Postgres 引擎認為它不相關/返回 0 行之外，沒有令人滿意的解釋。
  2. 我是否應該從查詢計劃中查看/擔心總成本 4984972.45 和計劃行 111195272.，即使它說從未執行？
  3. 什麼會導致在等待狀態 BufFileWrite 中花費過多的時間？據我了解，當應用排序/過濾器時，會使用臨時文件，這顯示為 BufFileWrite 等待狀態。監控_Postgres
  4. 您建議我從哪裡開始，以減少查詢在 BufFileWrite 的 IO 等待狀態下花費的時間？- 我嘗試過，真空，重新索引，添加新的部分索引 - 但沒有幫助。
  5. 我想到的一件事是，不要使用students_points表格（它有 1 行，對於每個學生，對於每次測試，他每週都參加，超過 4 年）所以它建立得很快，而是創建一個只容納每個學生的最新點（因此只有與學生一樣多的行）並在查詢中使用它。

任何幫助表示讚賞。提前致謝。如果您需要更多資訊，我很樂意提供。

查詢和計劃

EXPLAIN (ANALYZE, COSTS, VERBOSE, BUFFERS, TIMING, SUMMARY) 
SELECT 
   SUM(CASE WHEN just_pass = 1 THEN 1 ELSE 0 END) point,
   SUM(CASE WHEN week_of_birthday = TRUE THEN 1 ELSE 0 END) birthday, 
   SUM(CASE WHEN fresh_grad = 1 THEN 1 ELSE 0 end) fresher, 
   SUM(CASE WHEN intervention_type::INT = 2 OR intervention_type::INT = 3 THEN 1 ELSE 0 END) attention 
FROM 
   (
       SELECT 
           checkins.student_id, intercepts.intervention_type ,max(evaluation_date), just_pass, 
           compute_week_of_birthday(student_birthdate, 4 , 'US/Central') as week_of_birthday, 
           CASE 
               WHEN student_enrolment_date NOTNULL AND student_enrolment_date >= '2017-01-29' AND student_enrolment_date < '2016-11-30' 
               THEN 1 ELSE 0 END AS fresh_grad 
           FROM 
           (
               SELECT 
                   student_id 
               FROM 
                   checkin_table 
               WHERE 
                   house_id = 9001 
               AND 
                   timestamp> '2019-06-11 01:00:40' AND timestamp<= '2019-06-11 01:00:50'
               GROUP BY 
               student_id
           ) 
           checkins 
       LEFT JOIN 
           students 
       ON 
           checkins.student_id = students.student_id 
       LEFT JOIN 
           students_points points 
       ON 
           checkins.student_id = points.student_id 
       LEFT JOIN 
           (
               select 
                   record_id, student_id, intervention_type, intervention_date
               FROM 
                   intervention_table 
               WHERE 
                   intervention_date 
               IN 
                   (
                       SELECT 
                           MAX(intervention_date) 
                       FROM 
                           intervention_table 
                       GROUP BY 
                           student_id
                   )
           ) AS intercepts 
       ON 
           checkins.student_id = intercepts.student_id 
       WHERE 
           date_part('year',age(student_birthdate)) >=18 
       AND 
           lower(registration_type_description) !~* '.*temporary.*' 
       GROUP BY 
           checkins.student_id, students.student_enrolment_date, student_birthdate, just_pass, intercepts.intervention_type
   ) AS result 
WHERE 
   max IN 
       (
           SELECT 
               evaluation_date 
           FROM 
               students_points 
           ORDER BY 
               evaluation_date DESC LIMIT 1
       ) 
       OR 
   max ISNULL;
                                                                                                                                                                                                                                                                                                                                                                                                                                                                     QUERY PLAN                                                                                                                                                                                                                                                                                                                                                                                                                                                                      
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Aggregate  (cost=74433.83..74433.84 rows=1 width=32) (actual time=0.081..0.081 rows=1 loops=1)
  Output: sum(CASE WHEN (result.just_pass = 1) THEN 1 ELSE 0 END), sum(CASE WHEN result.week_of_birthday THEN 1 ELSE 0 END), sum(CASE WHEN (result.fresh_grad = 1) THEN 1 ELSE 0 END), sum(CASE WHEN (((result.intervention_type)::integer = 2) OR ((result.intervention_type)::integer = 3)) THEN 1 ELSE 0 END)
  Buffers: shared hit=20
  ->  Subquery Scan on result  (cost=74412.92..74432.98 rows=34 width=15) (actual time=0.079..0.079 rows=0 loops=1)
        Output: result.student_id, result.intervention_type, result.max, result.just_pass, result.week_of_birthday, result.fresh_grad, students.student_enrolment_date, students.student_birthdate
        Filter: ((hashed SubPlan 1) OR (result.max IS NULL))
        Buffers: shared hit=20
        ->  GroupAggregate  (cost=74412.31..74431.52 rows=68 width=35) (actual time=0.079..0.079 rows=0 loops=1)
              Output: checkin_table.student_id, intervention_table.intervention_type, max(points.evaluation_date), points.just_pass, compute_week_of_birthday(students.student_birthdate, 4, 'US/Central'::text), CASE WHEN ((students.student_enrolment_date IS NOT NULL) AND (students.student_enrolment_date >= '2017-01-29'::date) AND (students.student_enrolment_date < '2016-11-30'::date)) THEN 1 ELSE 0 END, students.student_enrolment_date, students.student_birthdate
              Group Key: checkin_table.student_id, students.student_enrolment_date, students.student_birthdate, points.just_pass, intervention_table.intervention_type
              Buffers: shared hit=20
              ->  Sort  (cost=74412.31..74412.48 rows=68 width=30) (actual time=0.078..0.078 rows=0 loops=1)
                    Output: checkin_table.student_id, intervention_table.intervention_type, points.just_pass, students.student_enrolment_date, students.student_birthdate, points.evaluation_date
                    Sort Key: checkin_table.student_id, students.student_enrolment_date, students.student_birthdate, points.just_pass, intervention_table.intervention_type
                    Sort Method: quicksort  Memory: 25kB
                    Buffers: shared hit=20
                    ->  Nested Loop Left Join  (cost=70384.64..74410.24 rows=68 width=30) (actual time=0.035..0.035 rows=0 loops=1)
                          Output: checkin_table.student_id, intervention_table.intervention_type, points.just_pass, students.student_enrolment_date, students.student_birthdate, points.evaluation_date
                          Buffers: shared hit=6
                          ->  Nested Loop Left Join  (cost=70384.08..74151.91 rows=1 width=22) (actual time=0.035..0.035 rows=0 loops=1)
                                Output: checkin_table.student_id, intervention_table.intervention_type, students.student_birthdate, students.student_enrolment_date
                                Buffers: shared hit=6
                                ->  Nested Loop  (cost=8.90..25.46 rows=1 width=16) (actual time=0.034..0.034 rows=0 loops=1)
                                      Output: checkin_table.student_id, students.student_birthdate, students.student_enrolment_date
                                      Buffers: shared hit=6
                                      ->  Group  (cost=8.46..8.47 rows=2 width=8) (actual time=0.034..0.034 rows=0 loops=1)
                                            Output: checkin_table.student_id
                                            Group Key: checkin_table.student_id
                                            Buffers: shared hit=6
                                            ->  Sort  (cost=8.46..8.47 rows=2 width=8) (actual time=0.033..0.033 rows=0 loops=1)
                                                  Output: checkin_table.student_id
                                                  Sort Key: checkin_table.student_id
                                                  Sort Method: quicksort  Memory: 25kB
                                                  Buffers: shared hit=6
                                                  ->  Append  (cost=0.00..8.45 rows=2 width=8) (actual time=0.027..0.027 rows=0 loops=1)
                                                        Buffers: shared hit=6
                                                        ->  Seq Scan on public.checkin_table  (cost=0.00..0.00 rows=1 width=8) (actual time=0.002..0.002 rows=0 loops=1)
                                                              Output: checkin_table.student_id
                                                              Filter: ((checkin_table.checkin_time > '2019-06-11 01:00:40+00'::timestamp with time zone) AND (checkin_table.checkin_time <= '2019-06-11 01:00:50+00'::timestamp with time zone) AND (checkin_table.house_id = 9001))
                                                        ->  Index Scan using checkins_y2019_m6_house_id_timestamp_idx on public.checkins_y2019_m6  (cost=0.43..8.45 rows=1 width=8) (actual time=0.024..0.024 rows=0 loops=1)
                                                              Output: checkins_y2019_m6.student_id
                                                              Index Cond: ((checkins_y2019_m6.house_id = 9001) AND (checkins_y2019_m6.checkin_time > '2019-06-11 01:00:40+00'::timestamp with time zone) AND (checkins_y2019_m6.checkin_time <= '2019-06-11 01:00:50+00'::timestamp with time zone))
                                                              Buffers: shared hit=6
                                      ->  Index Scan using students_student_id_idx on public.students  (cost=0.43..8.47 rows=1 width=16) (never executed)
                                            Output: students.student_type, students.house_id, students.registration_id, students.registration_status, students.registration_type_status, students.total_non_core_subjects, students.registration_source, students.total_core_subjects, students.registration_type_description, students.non_access_flag, students.address_1, students.address_2, students.city, students.state, students.zipcode, students.registration_created_date, students.registration_activation_date, students.registration_cancellation_request_date, students.registration_termination_date, students.cancellation_reason, students.monthly_dues, students.student_id, students.student_type, students.student_status, students.student_first_name, students.student_last_name, students.email_address, students.student_enrolment_date, students.student_birthdate, students.student_gender, students.insert_time, students.update_time
                                            Index Cond: (students.student_id = checkin_table.student_id)
                                            Filter: ((lower((students.registration_type_description)::text) !~* '.*temporary.*'::text) AND (date_part('year'::text, age((CURRENT_DATE)::timestamp with time zone, (students.student_birthdate)::timestamp with time zone)) >= '18'::double precision))
                                ->  Nested Loop  (cost=70375.18..74126.43 rows=2 width=14) (never executed)
                                      Output: intervention_table.intervention_type, intervention_table.student_id
                                      Join Filter: (intervention_table.intervention_date = (max(intervention_table_1.intervention_date)))
                                      ->  HashAggregate  (cost=70374.75..70376.75 rows=200 width=8) (never executed)
                                            Output: (max(intervention_table_1.intervention_date))
                                            Group Key: max(intervention_table_1.intervention_date)
                                            ->  HashAggregate  (cost=57759.88..63366.49 rows=560661 width=16) (never executed)
                                                  Output: max(intervention_table_1.intervention_date), intervention_table_1.student_id
                                                  Group Key: intervention_table_1.student_id
                                                  ->  Seq Scan on public.intervention_table intervention_table_1  (cost=0.00..46349.25 rows=2282125 width=16) (never executed)
                                                        Output: intervention_table_1.record_id, intervention_table_1.student_id, intervention_table_1.intervention_type, intervention_table_1.intervention_date, intervention_table_1.house_id, intervention_table_1.teacher_id, intervention_table_1.expiration_date, intervention_table_1.point_at_intervention
                                      ->  Index Scan using intervention_table_student_id_idx on public.intervention_table  (cost=0.43..18.70 rows=4 width=22) (never executed)
                                            Output: intervention_table.record_id, intervention_table.student_id, intervention_table.intervention_type, intervention_table.intervention_date, intervention_table.house_id, intervention_table.teacher_id, intervention_table.expiration_date, intervention_table.point_at_intervention
                                            Index Cond: (checkin_table.student_id = intervention_table.student_id)
                          ->  Index Scan using students_latest_points_idx on public.students_points points  (cost=0.57..257.65 rows=68 width=16) (never executed)
                                Output: points.record_id, points.student_id, points.registration_id, points.house_id, points.evaluation_date, points.just_pass, points.five_star, points.star1, points.star2, points.star3, points.star4, points.updatedate
                                Index Cond: (checkin_table.student_id = points.student_id)
        SubPlan 1
          ->  Limit  (cost=0.57..0.61 rows=1 width=4) (never executed)
                Output: students_points.evaluation_date
                ->  Index Only Scan Backward using students_points_evaluation_date_idx on public.students_points  (cost=0.57..4984972.45 rows=111195272 width=4) (never executed)
                      Output: students_points.evaluation_date
                      Heap Fetches: 0
Planning time: 23.993 ms
Execution time: 17.648 ms
(72 rows)

PS：出於隱私考慮，替換了表的名稱和屬性。一開始，我似乎可以students_points按年份對錶格進行分區，但這不是團隊願意接受的選項，原因我無法指定，而且根據年份對錶格進行分區也沒有意義，因為大多數我們的連接已經打開student_id，並且分區student_id將導致 1M+ 分區。

編輯以解決 Jjanes評論。

  1. checkin_table似乎是空的-checkin_table是一個分區表。查詢實際上命中了分區 - checkins_y2019_m6，該分區實際上有數據。
  2. 是什麼讓你認為這個查詢是罪魁禍首？- 在高峰時間使用 PGBadger 時，看到 40 個 DB 連接中有 30 個處於等待狀態。查看這些連接的查詢，它與上面描述的查詢相同 - 但具有不同的house_id和組合checkin_time。此外，根據 RDS 洞察（上圖 1），如果您查看螢幕截圖的底部，它在**按等待載入 (AAS)**下方有條形圖，您可以看到條形圖的 2/3 是淺藍色 (IOWait) 和 1/3 是綠色 (CPU) 和相應的查詢。查看附加的 pgbadger 視圖（編輯查詢詳細資訊）。此查詢是最耗時的查詢。 Redacted_PgBadger_Long_Running_Query
  3. pg_stat_statements- 是的，我看過它這是關於 total_time desc 的最高查詢，它與 PG Badger 一致。 pg_stat_statements
  4. **auto_explain**看起來可行。只有一個問題——它會以任何方式妨礙性能嗎？
  5. 關於 IO Churn 和最慢的查詢- 我同意，但我遇到了死胡同並且沒有想法了。就像你指出的那樣，我可能會誤解一些事情。我沒有查看寫入臨時文件的所有查詢，這可能會佔用緩衝區，導致此處出現 IOWait。

編輯添加解決方案：

後端團隊重新編寫了sql查詢，性能有所提升。這將查詢執行時間降低到毫秒。

“evaluation_date”的值只需要從 GroupAggregate 中過濾掉行。由於不返回任何行，因此無需執行找到“evaluation_date”值的子計劃。

您不應該擔心這筆費用。即使執行了查詢的那部分，由於限制，它仍然會很快。一個節點的報告成本估算是在它執行到完成的假設下進行的。按比例降低成本是其上方 LIMIT 節點的工作。

表 checkin_table 似乎是空的。這很奇怪，不是嗎？

導致過多 BufFileWrite 的原因不是此查詢，或者至少不是您顯示的查詢實例——也許在其他情況下，它會使用非空的 checkin_table 執行。是什麼讓你認為這個查詢是罪魁禍首？您提到了幾種不同的工具，但除了您誤解的 LIMITed 索引掃描的總成本估算之外，您沒有說明這些工具特別向您展示了什麼。

您可以使用pg_stat_statements來查看平均或總體上哪些查詢很慢，並且可以使用“log_min_duration_statement”或更好的auto_explain來查看哪些特定的執行單獨很慢。

您最慢的查詢不一定會導致所有這些 IO 流失，但導致如此多的 IO 流失的任何事情都需要至少有點慢。所以你最好的選擇是從最慢的開始。

我根據您的情況製作了表格和查詢。即使它們與您的不同，也將有助於解決問題。

create table students
(student_id integer,
student_name varchar(100));

create table student_point
(student_id integer,
exam_seq   integer,
points     integer
);
create index idx_student_point_02 on student_point(exam_seq,student_id);

create table check_in_table
( check_dt timestamp,
 house_no integer,
 student_id integer
);
create index idx_check_in_table_01 on check_in_table(house_no,check_dt);

create table intervention_table
(student_id integer,
intervention_date timestamp,
intervention_type varchar(1));

create index idx_test on intervention_table(student_id,intervention_date, intervention_type);

-- insert sample data
insert into students
with ch as 
(
   select chr(i+96) as c from generate_series(1,25) i
)
select row_number() over() as student_id, 
      c1||c2||c3 as student_name
from 
(select c c1 from ch) a,
(select c c2 from ch) b,
(select c c3 from ch) c,
(select i from generate_series(1,50) i) d;
commit;

insert into student_point
select student_id, row_number() over(partition by student_id) as exam_seq, trunc(random() * 100+1) as points
from students, ( select i from generate_series(1,5) i) j;
commit;

--For invention_table data, I lost sql scripts. sorry :(

--10 second delay
select pg_sleep(10);

--the numbers below are just random : I just want to show numbers in no order.  I executed these insert queries repeatedly.
insert into check_in_table 
select now() as check_dt, trunc(random() * 10+1) as room_no, student_id 
from students
where student_id between ( select trunc(random()*5733) as student_id ) and ( select trunc(random()*23467) as student_id )
limit 32231;
commit;

select pg_sleep(10);

insert into check_in_table 
select now() as check_dt, trunc(random() * 10+1) as room_no, student_id 
from students
where student_id between ( select trunc(random()*15801) as student_id ) and ( select trunc(random()*35154) as student_id )
limit 14332;
commit;

select pg_sleep(10);

insert into check_in_table 
select now() as check_dt, trunc(random() * 10+1) as room_no, student_id 
from students
where student_id between ( select trunc(random()*98752) as student_id ) and ( select trunc(random()*112506) as student_id )
limit 24233;
commit;

select pg_sleep(10);

insert into check_in_table 
select now() as check_dt, trunc(random() * 10+1) as room_no, student_id 
from students
where student_id between ( select trunc(random()*551500) as student_id ) and ( select trunc(random()*570000) as student_id )
limit 14391;
commit;

--query before tuning : really slow and causing a heavy cpu load & buffwrite for a long time 
SELECT SUM(points) points
     ,SUM(CASE WHEN intervention_type::INT = 2 OR intervention_type::INT = 3 THEN 1 ELSE 0 END) attention 
FROM 
   (
       SELECT 
           checkins.student_id, intercepts.intervention_type ,max(exam_seq), sum(sp.points) as points
           FROM 
           (
               SELECT 
                   student_id 
               FROM 
                   check_in_table 
               WHERE 
                 house_no = 1
               AND 
                   check_dt> '2020-07-08 12:44:47' AND check_dt<= '2020-07-08 12:44:57'
               GROUP BY student_id
           ) 
           checkins 
       LEFT JOIN 
           students 
       ON 
           checkins.student_id = students.student_id 
       LEFT JOIN 
           student_point sp
       ON 
           checkins.student_id = sp.student_id 
       LEFT JOIN 
           (
               select record_id, student_id, intervention_type, intervention_date
               FROM intervention_table i1
               WHERE (student_id, intervention_date) in 
                    (
                       SELECT student_id, MAX(intervention_date) 
                       FROM intervention_table 
                       GROUP BY student_id
                    )   
           ) AS intercepts 
       ON 
           checkins.student_id = intercepts.student_id 
       GROUP BY 
           checkins.student_id, intercepts.intervention_type
   ) AS result 
WHERE 
   max IN 
       (
           SELECT 
               exam_seq 
           FROM 
               student_point 
           ORDER BY 
               exam_seq DESC LIMIT 1
       ) 
       OR 
   max ISNULL;


--query after tuning
with checkins as
(   
   SELECT student_id 
   FROM 
       check_in_table 
   WHERE 
     house_no = 1
   AND 
       check_dt> '2020-07-08 12:44:47' AND check_dt<= '2020-07-08 12:44:57'
   GROUP BY student_id
)
SELECT SUM(points) points
     ,SUM(CASE WHEN intervention_type::INT = 2 OR intervention_type::INT = 3 THEN 1 ELSE 0 END) attention 
FROM 
   (
       SELECT /*+ Leading(checkins students) */
           checkins.student_id, intercepts.intervention_type ,max(exam_seq), sum(sp.points) as points
       FROM checkins 
       LEFT JOIN 
           students 
       ON 
           checkins.student_id = students.student_id 
       LEFT JOIN 
           student_point sp
       ON 
           checkins.student_id = sp.student_id 
       LEFT JOIN 
           (
               select record_id, student_id, intervention_type, intervention_date
               FROM intervention_table i1
               WHERE (student_id,intervention_date) in 
                    (
                       SELECT  i2.student_id, MAX(intervention_date) 
                       FROM intervention_table i2
                           ,checkins           c
                       WHERE i2.student_id = c.student_id
                       GROUP BY i2.student_id
                    )   
           ) AS intercepts 
       ON 
           checkins.student_id = intercepts.student_id 
       GROUP BY 
           checkins.student_id, intercepts.intervention_type
   ) AS result 
WHERE 
   max IN 
       (
           SELECT 
               exam_seq 
           FROM 
               student_point 
           ORDER BY 
               exam_seq DESC LIMIT 1
       ) 
       OR 
   max ISNULL;

引用自：https://dba.stackexchange.com/questions/240940

相關問答

Sql-Server

PAGEIOLATCH 等待和頁面預期壽命非常低

  • October 14, 2020
檢視問答
Sql-Server

sp_WhoIsActive 等待資源

  • January 11, 2019
檢視問答
Sql-Server

RAM中的邏輯讀取是否出現在等待統計中或在哪裡？

  • August 16, 2018
檢視問答
Sql-Server

巨大的“網路 I/O”類型資源等待

  • May 19, 2017
檢視問答
Postgresql

PostgreSQL 規劃器對分佈不均勻的列的錯誤決策

  • August 3, 2022
檢視問答
Performance

找出哪些查詢會受到對 CTFP 的擬議變更的影響

  • May 6, 2022
檢視問答