Why are my postgresql update times getting less timely?

Preamble

A customer recently questioned me about why a bulk load into a PostgreSQL table continued slowing down over time. They saw that the trigger on the table was getting slower and slower, and that the updates were also getting slower. Now that sluggish updates are a common problem, I thought it might be interesting to dig a little deeper into what’s going on. 

An example that demonstrates updates getting slower in PostgreSQL

Definitions of objects

A table that receives heavy weights is the setting for our case. We keep a summary table that is kept up to date by a trigger because we often need to find out how much each item in the table adds up to (for more information, see this article): 

CREATE TABLE item ( id bigint GENERATED ALWAYS AS IDENTITY, value bigint NOT NULL ); CREATE TABLE sum ( total bigint NOT NULL ); INSERT INTO sum VALUES (0); CREATE FUNCTION add_to_sum() RETURNS trigger LANGUAGE plpgsql AS $$BEGIN UPDATE sum SET total = total + NEW.value; RETURN NEW; END;$$; CREATE CONSTRAINT TRIGGER add_to_sum AFTER INSERT ON item DEFERRABLE INITIALLY DEFERRED FOR EACH ROW EXECUTE FUNCTION add_to_sum(); 

This change occurs at the very end of the transaction because we are employing a postponed constraint trigger. So that we can achieve the highest level of concurrency, the row in the sum table is not locked for any longer than is strictly necessary. In order to receive quick HOT updates, we are careful not to index sum (which would be tempting to ensure that there is only a single row).

What do we do when we bulk load

With a script similar to this, we will bulk load the table:

\timing on COPY item (value) FROM STDIN; 11638 422 17165 [a total of 100000 random numbers] \. 

​We must run this script using psql because it contains both data and a COPY statement:

psql -d dbname -f script.sql 

​The given script takes 60 seconds to load 100000 rows on my machine, which is an absurdly lengthy time. When I drop the trigger on an object, the same script runs in less than 70 ms. ​

How to prove that the problem is updates getting slower?

There is no doubt that the trigger is the issue, as the trigger function only has one UPDATE statement. Why does it take so long to say that? The auto-explanation extension allows us to view specifics regarding how each UPDATE statement was executed. To accomplish this, we add the lines below to postgresql.conf:

shared_preload_libraries = 'auto_explain' auto_explain.log_min_duration = 0 auto_explain.log_analyze = on auto_explain.log_buffers = on auto_explain.log_wal = on auto_explain.log_nested_statements = on 

For the modified shared preload libraries setting to take effect, PostgreSQL needs to be restarted. Note that I wouldn’t want to use these settings on a server that is often used. For starters, if you set auto explain.log analyze = on, all sentences will be logged, which may load up your disk. Additionally, all statements will execute much more slowly if auto explain.log analyze = on since PostgreSQL will then track each statement’s progress in great detail.

If we redo the experiment, we receive a log for each of the 100,000 UPDATE statements from the trigger, and the outcome is instructive:

The first UPDATE

Query Text: UPDATE sum SET total = total + NEW.value Update on sum (cost=0.00..38.25 rows=0 width=0) (actual time=0.016..0.017 rows=0 loops=1) Buffers: shared hit=3 WAL: records=1 bytes=74 -> Seq Scan on sum (cost=0.00..38.25 rows=2260 width=14) (actual time=0.005..0.005 rows=1 loops=1) Buffers: shared hit=1 

​Then, as the process proceeds more slowly, until the 100000th UPDATE, which reads:​

Query Text: UPDATE sum SET total = total + NEW.value Update on sum (cost=0.00..38.25 rows=0 width=0) (actual time=1.641..1.641 rows=0 loops=1) Buffers: shared hit=445 WAL: records=1 bytes=74 -> Seq Scan on sum (cost=0.00..38.25 rows=2260 width=14) (actual time=1.637..1.637 rows=1 loops=1) Buffers: shared hit=443 

Explaining the cause of updates getting slower

Row variants continue to grow.

It is obvious that the time is being used to sequentially scan the total, which must be expanding to 443 8kB-pages in size. To comprehend that, keep in mind that an UPDATE in PostgreSQL adds a new row version to the table rather than overwriting the existing record. This is comparable to a DELETE followed by an INSERT, though not precisely the same. Therefore, the table receives 100,000 new row versions as a result of the 100,000 UPDATEs.

Vacuums can’t do the cleaning.

These “dead row versions” created by UPDATE statements have to be removed by VACUUM. The autovacuum procedure often handles this automatically. Why then, does it not apply to us? Due to the fact that VACUUM can only remove row versions that predate any currently running transaction, this is the cause. However, our COPY statement just requires one transaction, which is typically a good thing because it speeds up bulk loading. Therefore, autovacuum can only remove the dead row versions from the sum after the COPY command has been completed, and by then, the sum table has already grown excessively large.

HEAT pruning is also ineffective.

But hold on, we specifically planned for HOT updates so that PostgreSQL wouldn’t need to run VACUUM to remove dead row versions. Every SQL statement can perform HOT pruning.However, HOT pruning has the same restriction as VACUUM and is unable to remove row versions from active transactions.

Indexes are useless.

When you initially look at the slow execution plan, you might assume that it’s because PostgreSQL uses a sequential scan rather than an index, which would speed up processing. With the sum table defined as it is now, that would not be possible, but we could add a primary key field. PostgreSQL would still need to follow the HOT chain within each block to the finish, which would hurt performance rather than help it. Additionally, every UPDATE that is not HOT (because of a lack of space on the current page) would generate a new (similar) primary key index entry, requiring us to visit every page of the table in order to browse through these entries. An index would therefore, if anything, make the update slower.

Examining the table with pageinspect

Argumentation is one thing, but seeing the statistics in the table itself is more persuasive. A superuser can view all the data in a table using the functions from the pageinspect extension, but normally we are unable to examine dead row versions. We can see what is on the first page of sum if we act quickly and run the following query after COPY but before autovacuum has cleaned up the table:

SELECT format('(0,%s)', lp) AS tid, t_ctid AS replacement, t_xmax <> 0 AS dead, t_infomask2 & 16384 <> 0 AS hot_updated, t_attrs[1] AS total FROM heap_page_item_attrs(get_raw_page('sum', 0), 'sum'); 

This will have the following effects:

 tid │ replacement │ dead │ hot_updated │ total ═════════╪═════════════╪══════╪═════════════╪════════════════════ (0,1) │ (0,2) │ t │ t │ \x0000000000000000 (0,2) │ (0,3) │ t │ t │ \x214e000000000000 (0,3) │ (0,4) │ t │ t │ \xe766000000000000 (0,4) │ (0,5) │ t │ t │ \xeaa0000000000000 (0,5) │ (0,6) │ t │ t │ \x9113010000000000 (0,6) │ (0,7) │ t │ t │ \x5c23010000000000 ... (0,225) │ (0,226) │ t │ t │ \x1356380000000000 (0,226) │ (1,1) │ t │ f │ \xab99380000000000 (226 rows) 

​Every entry is dead (xmax is set), every entry replaces the one before it, and every update—aside from the final one, which added a row to the following page—was HOT.​

A remedy for updates getting slower

​The issue is now evident, and the answer is simple: avoid repeatedly updating the same row in a single transaction. The specifics of the initial workload will determine the best method to prevent this. A transition table-based statement level trigger might be one potential solution.​

DROP TRIGGER add_to_sum ON item; CREATE OR REPLACE FUNCTION add_to_sum() RETURNS trigger LANGUAGE plpgsql AS $$BEGIN UPDATE sum SET total = total + (SELECT sum(value) FROM new_rows); RETURN NULL; END;$$; CREATE TRIGGER add_to_sum AFTER INSERT ON item REFERENCING NEW TABLE AS new_rows FOR EACH STATEMENT EXECUTE FUNCTION add_to_sum(); 

​For each COPY statement with this trigger, only one UPDATE on the sum will be executed. With it, the bulk load on my machine completes in just under 90 milliseconds!​

Conclusion

​If you consistently update the same rows in a single transaction, this is the most frequent cause of updates becoming slower over time. The easiest thing to do is to avoid updating the same row over and over again, since only the last update of a row in a transaction will be seen. ​

About Enteros

​​​​Enteros offers a patented database performance management SaaS platform. It proactively identifies root causes of complex business-impacting database scalability and performance issues across a growing number of clouds, RDBMS, NoSQL, and machine learning database platforms.​