2020-09-01 12:13:01.872
a2dfe3bb-5633-45d4-c71d-18c7aab95f39
 1.547 ms
сообщить о проблеме
IB#9
RRIB#10
tilemap |  piechart
time | buffers | i/otilemap
#
node, ms
io.rd, ms
tree, ms
rows
RRbF
loops
sh.ht
sh.rd
sh.dr
126′171.348
43′606.484126′622
итоговые результаты
average IO: read random=2.60MB/s
scan=2′054′106
2′012′054
42′052
9′309
0
43′606.484
Nested Loop
1
.001
43′606.484
  ->  Nested Loop
2
43′606.483
       ->  Nested Loop
3
.002
43′606.483
            ->  GroupAggregate
4
.009
43′606.481
                 ->  Sort
5
43′606.472
                      ->  Nested Loop
6
41′072.084
640′984
▲
                           ->  Gather
7
150.233
127′110.456
640′983
▲
3
                                ->  Nested Loop
8
84.045
18′693
▼
107′928
85.2%
3
                                     ->  Parallel Seq Scan on sgm_events_mv sgme1
9′082
9
126′876.178
126′171.348
635′596
▲
18′694
2.9%
18′694
IB
                                     ->  Index Scan using ai_student_id_event_time_idx on assessment_item ai
80′020
42′052
9′309
10
2′563.936
640′984
RRIB
                           ->  Index Scan using standard_item_id_idx on standard s1
1′922′952
11
n/e
            ->  Index Scan using sgm_events_staging_pkey on sgm_events_staging sgme
12
n/e
       ->  Index Scan using domain_standards_pkey on domain_standards ds
13
n/e
  ->  Index Scan using domains_pkey on domains d
2.207
 
Planning Time
.248
43′606.732
Execution Time
 
Nested Loop  (cost=107′334.16..120′692.72 rows=875 width=646) (actual time=43′606.484..43′606.484 rows=0 loops=1)
  Buffers: shared hit=2′012′054 read=42′052 dirtied=9′309
  I/O Timings: read=126′171.348
  ->  Nested Loop  (cost=107′333.88..120′417.67 rows=875 width=502) (actual time=43′606.484..43′606.484 rows=0 loops=1)
        Buffers: shared hit=2′012′054 read=42′052 dirtied=9′309
        I/O Timings: read=126′171.348
        ->  Nested Loop  (cost=107′333.46..113′646.85 rows=875 width=330) (actual time=43′606.483..43′606.483 rows=0 loops=1)
              Buffers: shared hit=2′012′054 read=42′052 dirtied=9′309
              I/O Timings: read=126′171.348
              ->  GroupAggregate  (cost=107′333.04..107′361.48 rows=875 width=129) (actual time=43′606.483..43′606.483 rows=0 loops=1)
                    Group Key: sgme1.activity_id, s1.standard_guid
                    Buffers: shared hit=2′012′054 read=42′052 dirtied=9′309
                    I/O Timings: read=126′171.348
                    ->  Sort  (cost=107′333.04..107′335.23 rows=875 width=101) (actual time=43′606.481..43′606.481 rows=0 loops=1)
                          Sort Key: sgme1.activity_id, s1.standard_guid
                          Sort Method: quicksort  Memory: 25kB
                          Buffers: shared hit=2′012′054 read=42′052 dirtied=9′309
                          I/O Timings: read=126′171.348
                          ->  Nested Loop  (cost=1′000.98..107′290.28 rows=875 width=101) (actual time=43′606.472..43′606.472 rows=0 loops=1)
                                Buffers: shared hit=2′012′054 read=42′052 dirtied=9′309
                                I/O Timings: read=126′171.348
                                ->  Gather  (cost=1′000.56..107′266.60 rows=16 width=57) (actual time=24.655..41′072.084 rows=640′984 loops=1)
                                      Workers Planned: 2
                                      Workers Launched: 2
                                      Buffers: shared hit=89′102 read=42′052 dirtied=9′309
                                      I/O Timings: read=126′171.348
                                      ->  Nested Loop  (cost=0.56..106′265.00 rows=7 width=57) (actual time=22.219..42′370.152 rows=213′661 loops=3)
                                            Buffers: shared hit=89′102 read=42′052 dirtied=9′309
                                            I/O Timings: read=126′171.348
                                            ->  Parallel Seq Scan on sgm_events_mv sgme1  (cost=0.00..10′137.11 rows=12′195 width=81) (actual time=19.548..28.015 rows=6′231 loops=3)
                                                  Filter: (((audit_created_datetime >= '2020-08-31 03:20:28'::timestamp without time zone) AND (audit_created_datetime <= '2020-09-01 03:20:28'::timestamp without time zone)) OR ((audit_modified_datetime >= '2020-08-31 03:20:28'::timestamp without time zone) AND (audit_modified_datetime <= '2020-09-01 03:20:28'::timestamp without time zone)))
                                                  Rows Removed by Filter: 35′976
                                                  Buffers: shared hit=9′082
                                            ->  Index Scan using ai_student_id_event_time_idx on assessment_item ai  (cost=0.56..7.87 rows=1 width=66) (actual time=4.242..6.787 rows=34 loops=18′694)
                                                  Index Cond: (((student_id)::text = (sgme1.student_id)::text) AND (event_time = sgme1.event_time))
                                                  Filter: attempted
                                                  Rows Removed by Filter: 1
                                                  Buffers: shared hit=80′020 read=42′052 dirtied=9′309
                                                  I/O Timings: read=126′171.348
                                ->  Index Scan using standard_item_id_idx on standard s1  (cost=0.42..1.10 rows=38 width=54) (actual time=0.004..0.004 rows=0 loops=640′984)
                                      Index Cond: ((item_id)::text = (ai.item_ref_id)::text)
                                      Buffers: shared hit=1′922′952
              ->  Index Scan using sgm_events_staging_pkey on sgm_events_staging sgme  (cost=0.42..7.17 rows=1 width=237) (never executed)
                    Index Cond: ((activity_id)::text = (sgme1.activity_id)::text)
        ->  Index Scan using domain_standards_pkey on domain_standards ds  (cost=0.42..7.74 rows=1 width=209) (never executed)
              Index Cond: ((standard_guid)::text = (s1.standard_guid)::text)
  ->  Index Scan using domains_pkey on domains d  (cost=0.29..0.31 rows=1 width=177) (never executed)
        Index Cond: ((domain_id)::text = (ds.domain_id)::text)

Planning Time: 2.207 ms
Execution Time: 43′606.732 ms
Join
  ->  Scan Table assessment_item
  ->  Scan Table domain_standards
  ->  Scan Table domains
  ->  Scan Table sgm_events_mv
  ->  Scan Table sgm_events_staging
  ->  Scan Table standard
                                                                                                                                                                                                QUERY PLAN                                                                     
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Nested Loop  (cost=107334.16..120692.72 rows=875 width=646) (actual time=43606.484..43606.484 rows=0 loops=1)
   Buffers: shared hit=2012054 read=42052 dirtied=9309
   I/O Timings: read=126171.348
   ->  Nested Loop  (cost=107333.88..120417.67 rows=875 width=502) (actual time=43606.484..43606.484 rows=0 loops=1)
         Buffers: shared hit=2012054 read=42052 dirtied=9309
         I/O Timings: read=126171.348
         ->  Nested Loop  (cost=107333.46..113646.85 rows=875 width=330) (actual time=43606.483..43606.483 rows=0 loops=1)
               Buffers: shared hit=2012054 read=42052 dirtied=9309
               I/O Timings: read=126171.348
               ->  GroupAggregate  (cost=107333.04..107361.48 rows=875 width=129) (actual time=43606.483..43606.483 rows=0 loops=1)
                     Group Key: sgme1.activity_id, s1.standard_guid
                     Buffers: shared hit=2012054 read=42052 dirtied=9309
                     I/O Timings: read=126171.348
                     ->  Sort  (cost=107333.04..107335.23 rows=875 width=101) (actual time=43606.481..43606.481 rows=0 loops=1)
                           Sort Key: sgme1.activity_id, s1.standard_guid
                           Sort Method: quicksort  Memory: 25kB
                           Buffers: shared hit=2012054 read=42052 dirtied=9309
                           I/O Timings: read=126171.348
                           ->  Nested Loop  (cost=1000.98..107290.28 rows=875 width=101) (actual time=43606.472..43606.472 rows=0 loops=1)
                                 Buffers: shared hit=2012054 read=42052 dirtied=9309
                                 I/O Timings: read=126171.348
                                 ->  Gather  (cost=1000.56..107266.60 rows=16 width=57) (actual time=24.655..41072.084 rows=640984 loops=1)
                                       Workers Planned: 2
                                       Workers Launched: 2
                                       Buffers: shared hit=89102 read=42052 dirtied=9309
                                       I/O Timings: read=126171.348
                                       ->  Nested Loop  (cost=0.56..106265.00 rows=7 width=57) (actual time=22.219..42370.152 rows=213661 loops=3)
                                             Buffers: shared hit=89102 read=42052 dirtied=9309
                                             I/O Timings: read=126171.348
                                             ->  Parallel Seq Scan on sgm_events_mv sgme1  (cost=0.00..10137.11 rows=12195 width=81) (actual time=19.548..28.015 rows=6231 loops=3)
                                                   Filter: (((audit_created_datetime >= '2020-08-31 03:20:28'::timestamp without time zone) AND (audit_created_datetime <= '2020-09-01 03:20:28'::timestamp without time zone)) OR ((audit_modified_datetime >= '2020-08-31 03:20:28'::timestamp without time zone) AND (audit_modified_datetime <= '2020-09-01 03:20:28'::timestamp without time zone)))
                                                   Rows Removed by Filter: 35976
                                                   Buffers: shared hit=9082
                                             ->  Index Scan using ai_student_id_event_time_idx on assessment_item ai  (cost=0.56..7.87 rows=1 width=66) (actual time=4.242..6.787 rows=34 loops=18694)
                                                   Index Cond: (((student_id)::text = (sgme1.student_id)::text) AND (event_time = sgme1.event_time))
                                                   Filter: attempted
                                                   Rows Removed by Filter: 1
                                                   Buffers: shared hit=80020 read=42052 dirtied=9309
                                                   I/O Timings: read=126171.348
                                 ->  Index Scan using standard_item_id_idx on standard s1  (cost=0.42..1.10 rows=38 width=54) (actual time=0.004..0.004 rows=0 loops=640984)
                                       Index Cond: ((item_id)::text = (ai.item_ref_id)::text)
                                       Buffers: shared hit=1922952
               ->  Index Scan using sgm_events_staging_pkey on sgm_events_staging sgme  (cost=0.42..7.17 rows=1 width=237) (never executed)
                     Index Cond: ((activity_id)::text = (sgme1.activity_id)::text)
         ->  Index Scan using domain_standards_pkey on domain_standards ds  (cost=0.42..7.74 rows=1 width=209) (never executed)
               Index Cond: ((standard_guid)::text = (s1.standard_guid)::text)
   ->  Index Scan using domains_pkey on domains d  (cost=0.29..0.31 rows=1 width=177) (never executed)
         Index Cond: ((domain_id)::text = (ds.domain_id)::text)
 Planning Time: 2.207 ms
 Execution Time: 43606.732 ms
# 9 Index Scan using ai_student_id_event_time_idx on assessment_item ai IB
Execution126′876.178ms97.8%: rows=635′596 (34) RRbF=18′694 (1), loops=18′694
Buffers131′3816.4%: hit=80′020, read=42′052, dirtied=9′309
I/O Timings126′171.348ms100.0%: read=126′171.348
Cost7.87: rows=1 width=66
Index Scan using ai_student_id_event_time_idx on assessment_item ai  (cost=0.56..7.87 rows=1 width=66) (actual time=4.242..6.787 rows=34 loops=18′694)
  Index Cond: (((student_id)::text = (sgme1.student_id)::text) AND (event_time = sgme1.event_time))
  Filter: attempted
  Rows Removed by Filter: 1
  Buffers: shared hit=80′020 read=42′052 dirtied=9′309
  I/O Timings: read=126′171.348
IB
->  Index Scan using ai_student_id_event_time_idx on assessment_item ai
    buffers=122072, rows=654290 (635596 + RRbF=18694), ratio=5.4
Рекомендации [подробнее]:
- таблица сильно разрежена, рекомендуется произвести очистку с помощью VACUUM [FULL]
- возможно, чтение идет "с середины" индекса
# 10 Index Scan using standard_item_id_idx on standard s1 RRIB
Execution2′563.936ms2.0%: rows=0, loops=640′984
Buffers1′922′95293.2%: hit=1′922′952
Cost1.10: rows=38 width=54
Index Scan using standard_item_id_idx on standard s1  (cost=0.42..1.10 rows=38 width=54) (actual time=0.004..0.004 rows=0 loops=640′984)
  Index Cond: ((item_id)::text = (ai.item_ref_id)::text)
  Buffers: shared hit=1′922′952
RR
->  Index Scan using standard_item_id_idx on standard s1
    rows-act=0, rows-pre=24357392
Рекомендации [подробнее]:
- сильно расходится плановая и фактическая статистика по таблице, стоит выполнить ее ANALYZE
IB
->  Index Scan using standard_item_id_idx on standard s1
    buffers=1922952, rows=0
Рекомендации [подробнее]:
- таблица сильно разрежена, рекомендуется произвести очистку с помощью VACUUM [FULL]
- возможно, чтение идет "с середины" индекса
Рекомендации :
- таблица сильно разрежена, рекомендуется произвести очистку с помощью VACUUM [FULL]
- возможно, чтение идет "с середины" индекса
#9
->  Index Scan using ai_student_id_event_time_idx on assessment_item ai
    buffers=122072, rows=654290 (635596 + RRbF=18694), ratio=5.4
#10
->  Index Scan using standard_item_id_idx on standard s1
    buffers=1922952, rows=0
Рекомендации :
- сильно расходится плановая и фактическая статистика по таблице, стоит выполнить ее ANALYZE
#10
->  Index Scan using standard_item_id_idx on standard s1
    rows-act=0, rows-pre=24357392
время % io.rd rows RRbF % loops тип узла таблица индекс узлы sh.ht sh.rd sh.dr
126′876.178
97.8
126′171.348
635′596
18′694
2.9
18′694
Index Scan
assessment_item
ai_student_id_event_time_idx
 9
80′020
42′052
9′309
2′563.936
2.0
640′984
Index Scan
standard
standard_item_id_idx
 10
1′922′952
150.234
0.1
640′983
7
Nested Loop

                          0 1 2 5 7
                        
                  
5

                        

                    
84.045

                  		
                
0.1

              		
                            
                          
                      
18′693

                  		
                  
107′928

                
85.2
 
                  
3

                
Parallel Seq Scan
sgm_events_mv

                          8
                        
                  
                        
                  
 9′082

                

                    
.009

                  		
                
0.0

              		
                            
                          
Sort

                          4
                        
                  
                        

                    
.002

                  		
                
0.0

              		
                            
                          
GroupAggregate

                          3
                        
                  
                        

                    
                  
                
              
                            
                          
                      
640′984

                  
Gather

                          6
                        
                  
                        

          

        

      

      

        
      

    

  

  
  

  
  
  
  
  
  
  
  
  
  
  
  
  
  
    
tooltip