×
Community Blog PostgreSQL v12: How pg_stat_statements Causes High-concurrency Performance Issues

PostgreSQL v12: How pg_stat_statements Causes High-concurrency Performance Issues

In this article, the author discusses how enabling PostgreSQL pg_stat_statements in PG v12 causes high-concurrency performance issues.

By digoal

Background

In PostgreSQL v12, after enabling the pg_stat_statements module, the lock bottleneck occurs under high concurrency. This severely degrades performance on a 104-thread machine even when pg_stat_statements.save is disabled.

perf top -ag --call-graph dwarf  

Samples: 619K of event 'cpu-clock', 4000 Hz, Event count (approx.): 28398325786 lost: 446528/15917886 drop: 406385/18784766                                                                         
  Children      Self  Shared Object           Symbol                                                                                                                                                
-   54.20%    54.20%  [kernel]                [k] cpuidle_enter_state                                                                                                                               
   - 5.52% 0xffffffff93a000d5                                                                                                                                                                       
      - 53.91% 0xffffffff93a59c97                                                                                                                                                                   
           0xffffffff93affc2a                                                                                                                                                                       
           0xffffffff93a37bce                                                                                                                                                                       
         - 0xffffffff93fbf9ae                                                                                                                                                                       
              53.90% 0xffffffff93fbf857                                                                                                                                                             
-   27.99%     0.21%  postgres                [.] PostgresMain                                                                                                                                      
   - 3.67% PostgresMain                                                                                                                                                                             
-   13.51%     0.01%  postgres                [.] finish_xact_command                                                                                                                               
-   13.50%     0.02%  postgres                [.] CommitTransactionCommand                                                                                                                          
-   13.48%     0.05%  postgres                [.] CommitTransaction                                                                                                                                 
-   12.45%     0.02%  postgres                [.] PreCommit_Portals                                                                                                                                 
-   12.35%     0.01%  postgres                [.] PortalDrop                                                                                                                                        
-   12.23%     0.01%  postgres                [.] PortalCleanup                                                                                                                                     
-   11.76%     0.02%  pg_stat_statements.so   [.] pgss_ExecutorEnd                                                                                                                                  
-   11.74%     0.44%  pg_stat_statements.so   [.] pgss_store                                                                                                                                        
   - 9.21% pgss_store                                                                                                                                                                               
      - 10.92% s_lock                                                                                                                                                                               
-   11.08%     8.89%  postgres                [.] s_lock                                                                                                                                            
     8.58% ServerLoop                                                                                                                                                                               
        BackendStartup (inlined)                                                                                                                                                                    
        BackendRun (inlined)                                                                                                                                                                        
        PostgresMain                                                                                                                                                                                
        finish_xact_command                                                                                                                                                                         
        CommitTransactionCommand                                                                                                                                                                    
        CommitTransaction                                                                                                                                                                           
        PreCommit_Portals                                                                                                                                                                           
        PortalDrop                                                                                                                                                                                  
        PortalCleanup                                                                                                                                                                               
        pgss_ExecutorEnd                                                                                                                                                                            
        pgss_store                                                                                                                                                                                  
        s_lock                                                                                                                                                                                      
-    7.75%     0.03%  postgres                [.] PortalRun                                                                                                                                         
-    7.57%     0.02%  postgres                [.] PortalRunSelect                                                                                                                                   
-    7.48%     0.04%  pg_stat_statements.so   [.] pgss_ExecutorRun                                                                                                                                  
     7.44%     0.03%  postgres                [.] standard_ExecutorRun                                                                                                                              
-    6.65%     0.04%  postgres                [.] ExecScan                                                                                                                                          
     6.54%     0.02%  postgres                [.] IndexNext                                                                                                                                         
     6.33%     0.01%  postgres                [.] index_getnext_slot                                                                                                                                
+    5.59%     0.00%  [unknown]               [k] 0xffffffff93a000d5                                                                                                                                
+    5.53%     0.00%  [unknown]               [k] 0xffffffff93a59c97                                                                                                                                
+    5.28%     0.00%  [unknown]               [k] 0xffffffff93affc2a                                                                                                                                
+    5.28%     0.00%  [unknown]               [k] 0xffffffff93a37bce  

Samples: 217K of event 'cpu-clock', 4000 Hz, Event count (approx.): 22185764626 lost: 411555/7098659 drop: 446791/8362859                                                                           
  Children      Self  Shared Object           Symbol                                                                                                                                                
-   55.76%    55.76%  [kernel]                [k] cpuidle_enter_state                                                                                                                               
   - 7.97% 0xffffffff93a000d5                                                                                                                                                                       
      - 55.37% 0xffffffff93a59c97                                                                                                                                                                   
           0xffffffff93affc2a                                                                                                                                                                       
           0xffffffff93a37bce                                                                                                                                                                       
           0xffffffff93fbf9ae                                                                                                                                                                       
-   29.82%     0.25%  postgres                [.] PostgresMain                                                                                                                                      
   - 4.16% PostgresMain                                                                                                                                                                             
      - 2.00% finish_xact_command                                                                                                                                                                   
         - 2.02% CommitTransactionCommand                                                                                                                                                           
            - 2.44% CommitTransaction                                                                                                                                                               
               - 1.90% PreCommit_Portals                                                                                                                                                            
                  - 1.83% PortalDrop                                                                                                                                                                
                     - 1.84% PortalCleanup                                                                                                                                                          
                        - 2.18% pgss_ExecutorEnd                                                                                                                                                    
                           - 10.32% pgss_store                                                                                                                                                      
                              - 10.77% s_lock                                                                                                                                                       
                                   1.30% perform_spin_delay                                                                                                                                         
      - 1.25% exec_execute_message (inlined)                                                                                                                                                        
-   13.87%     0.03%  postgres                [.] CommitTransactionCommand                                                                                                                          
     2.44% CommitTransactionCommand                                                                                                                                                                 
      - CommitTransaction                                                                                                                                                                           
         - 1.90% PreCommit_Portals                                                                                                                                                                  
            - 1.83% PortalDrop                                                                                                                                                                      
               - 1.84% PortalCleanup                                                                                                                                                                
                  - 2.18% pgss_ExecutorEnd                                                                                                                                                          
                     - 10.32% pgss_store                                                                                                                                                            
                        - 10.77% s_lock                                                                                                                                                             
                             1.30% perform_spin_delay                                                                                                                                               
-   13.84%     0.04%  postgres                [.] CommitTransaction                                                                                                                                 
   - 2.40% CommitTransaction                                                                                                                                                                        
      - 1.90% PreCommit_Portals                                                                                                                                                                     
         - 1.83% PortalDrop                                                                                                                                                                         
            - 1.84% PortalCleanup                                                                                                                                                                   
               - 2.18% pgss_ExecutorEnd                                                                                                                                                             
                  - 10.32% pgss_store                                                                                                                                                               
                     - 10.77% s_lock                                                                                                                                                                
                          1.30% perform_spin_delay                                                                                                                                                  
-   13.58%     0.01%  postgres                [.] finish_xact_command                                                                                                                               
     1.99% finish_xact_command                                                                                                                                                                      
-   12.63%     0.02%  postgres                [.] PreCommit_Portals                                                                                                                                 
   - 1.87% PreCommit_Portals                                                                                                                                                                        
      - 1.83% PortalDrop                                                                                                                                                                            
         - 1.84% PortalCleanup     

Comparison Test

pgbench -i -s 1000  

Enable pg_stat_statements

pgbench -M prepared -n -r -P 1 -c 104 -j 104 -T 120 -S  
  
transaction type: <builtin: select only>  
scaling factor: 1000  
query mode: prepared  
number of clients: 104  
number of threads: 104  
duration: 120 s  
number of transactions actually processed: 67468127  
latency average = 0.185 ms  
latency stddev = 0.348 ms  
tps = 562224.744452 (including connections establishing)  
tps = 562300.147713 (excluding connections establishing)  
statement latencies in milliseconds:  
         0.001  \set aid random(1, 100000 * :scale)  
         0.185  SELECT abalance FROM pgbench_accounts WHERE aid = :aid;  

Disable pg_stat_statements

pgbench -M prepared -n -r -P 1 -c 104 -j 104 -T 120 -S  
  
transaction type: <builtin: select only>  
scaling factor: 1000  
query mode: prepared  
number of clients: 104  
number of threads: 104  
duration: 120 s  
number of transactions actually processed: 187563515  
latency average = 0.066 ms  
latency stddev = 0.014 ms  
tps = 1562993.591525 (including connections establishing)  
tps = 1563258.811725 (excluding connections establishing)  
statement latencies in milliseconds:  
         0.001  \set aid random(1, 100000 * :scale)  
         0.065  SELECT abalance FROM pgbench_accounts WHERE aid = :aid;  

If you detect such a problem while using PG v12, it’s better not to load the pg_stat_statements module before the community solves the problem.

0 0 0
Share on

digoal

202 posts | 12 followers

You may also like

Comments