0

I ran this explain analyse in my PostgreSQL 13.7 database:

explain(analyze, verbose, buffers, settings) select * from main_table;
 Seq Scan on public.main_table  (cost=0.00..10246.15 rows=220715 width=687) (actual time=0.015..168.565 rows=220287 loops=1)
   Output: id, name, ...
   Buffers: shared hit=7243 read=796
 Planning Time: 0.139 ms
 Execution Time: 178.958 ms

The execution time is always between 160 and 200 ms.

I've dumped and restored the database in same machine and repeated the explain:

explain(analyze, verbose, buffers, settings) select * from main_table;
 Seq Scan on public.main_table  (cost=0.00..10198.86 rows=220286 width=689) (actual time=0.049..41.595 rows=220286 loops=1)
   Output: id, name, ...
   Buffers: shared read=7996
 Planning Time: 0.128 ms
 Execution Time: 51.647 ms

The execution time is always between 45 and 55 ms.

Why is the restored DB faster than the original? I executed VACUUM FULL and reindex database in original database, but execution time doesn't change. Can I do anything else?

NEW TEST WITH track_io_timing ON

I ran explain analyse three times in each database

ORIGINAL

 Seq Scan on public.main_table  (cost=0.00..10275.46 rows=221346 width=687) (actual time=0.025..181.509 rows=220527 loops=1)
   Output: id, name,...
   Buffers: shared hit=6355 read=1707
   I/O Timings: read=7.113
 Planning:
   Buffers: shared hit=318 read=60 dirtied=1
   I/O Timings: read=8.793
 Planning Time: 10.500 ms
 Execution Time: 191.809 ms
 
  Seq Scan on public.main_table  (cost=0.00..10275.46 rows=221346 width=687) (actual time=0.028..183.451 rows=220527 loops=1)
   Output: id, name,...
   Buffers: shared hit=328 read=7734
   I/O Timings: read=24.171
 Planning:
   Buffers: shared hit=314 read=64
   I/O Timings: read=0.859
 Planning Time: 2.411 ms
 Execution Time: 193.878 ms


 Seq Scan on public.main_table  (cost=0.00..10275.46 rows=221346 width=687) (actual time=0.048..174.678 rows=220527 loops=1)
   Output: id, name,...
   Buffers: shared hit=456 read=7606
   I/O Timings: read=21.949
 Planning Time: 0.289 ms
 Execution Time: 184.883 ms

RESTORED

 Seq Scan on public.main_table  (cost=0.00..10198.86 rows=220286 width=689) (actual time=1.199..277.902 rows=220286 loops=1)
   Output: id, name,...
   Buffers: shared read=7996
   I/O Timings: read=252.057
 Planning:
   Buffers: shared hit=341 read=40
   I/O Timings: read=33.752
 Planning Time: 35.319 ms
 Execution Time: 288.698 ms
 
  Seq Scan on public.main_table  (cost=0.00..10198.86 rows=220286 width=689) (actual time=0.107..47.826 rows=220286 loops=1)
   Output: id, name,...
   Buffers: shared hit=32 read=7964
   I/O Timings: read=26.934
 Planning Time: 0.140 ms
 Execution Time: 58.268 ms

 Seq Scan on public.main_table  (cost=0.00..10198.86 rows=220286 width=689) (actual time=0.058..42.252 rows=220286 loops=1)
   Output: id, name,...
   Buffers: shared read=7996
   I/O Timings: read=22.246
 Planning Time: 0.127 ms
 Execution Time: 51.822 ms

NEW TEST WITH ISOLATED DATABASE

I have now a isolated database without connections. I've restarted postgres before start with the tests. All tests are over same instance.

original=# vacuum full;
VACUUM

original=# reindex database original;
REINDEX

original=# explain(analyze, verbose, buffers, settings) select * from main_table;
 Seq Scan on public.main_table  (cost=0.00..10379.26 rows=223526 width=689) (actual time=0.127..178.371 rows=223526 loops=1)
   Output: id, name, ...
   Buffers: shared hit=352 read=7792
   I/O Timings: read=27.463
 Planning Time: 0.172 ms
 Execution Time: 188.395 ms

After I've created a copy from psql console

postgres=# create database restored template = original;
restored=# explain(analyze, verbose, buffers, settings) select * from main_table;
 Seq Scan on public.main_table  (cost=0.00..10379.26 rows=223526 width=689) (actual time=0.210..178.115 rows=223526 loops=1)
   Output: id, name, ...
   Buffers: shared hit=96 read=8048
   I/O Timings: read=20.545
 Planning Time: 0.195 ms
 Execution Time: 188.460 ms

It's a normal result, all values are the same. Then I've created a copy from linux console

/tmp$ pg_dump original > backup.psql
/tmp$ dropdb restored
/tmp$ createdb restored
/tmp$ psql restored < backup.psql

restored=# explain(analyze, verbose, buffers, settings) select * from main_table;
 Seq Scan on public.main_table  (cost=0.00..10349.26 rows=223526 width=687) (actual time=0.194..41.564 rows=223526 loops=1)
   Output: id, name, ...
   Buffers: shared hit=383 read=7731
   I/O Timings: read=20.332
 Planning Time: 0.193 ms
 Execution Time: 51.556 ms

Now the number of rows is the same, but width is less.

Any ideas? Can I launch some more tests to find out why the execution time is less on the restored database?

IMPORTANT TEST OVER SAME DATABASE

I saw main_table has two dropped columns...

original=# SELECT attnum, attname, attisdropped
         FROM pg_attribute a
         JOIN pg_class c ON c.oid = a.attrelid
         WHERE c.relname = 'main_table'
               AND c.relkind = 'r'
               AND a.attnum > 0 AND attisdropped = 't';
 attnum |            attname            | attisdropped
--------+-------------------------------+--------------
     34 | ........pg.dropped.34........ | t
     45 | ........pg.dropped.45........ | t

Then I've copied the table and launch explain...

original=# create table test (like main_table INCLUDING ALL);
CREATE TABLE
original=# INSERT INTO test select * from main_table;
INSERT 0 223526
original=# explain(analyze, verbose, buffers, settings) select * from test;
 Seq Scan on public.test  (cost=0.00..10349.26 rows=223526 width=689) (actual time=0.007..29.275 rows=223526 loops=1)
   Output: id, name, ...
   Buffers: shared hit=8114
 Planning:
   Buffers: shared hit=296 dirtied=36
 Planning Time: 0.795 ms
 Execution Time: 39.383 ms

Surprise! Execution time is perfect! Maybe the dropped columns hinders performance? I don't know, but it sounds weird

13
  • 1
    this belongs on Database Administrators Feb 13 at 15:55
  • Did you try VACUUM FULL on the original database? Rewriting all tables to optimize storage. When you use explain, please use explain(analyze, verbose, buffers, settings) to get the whole picture, including memory usage etc. Feb 13 at 16:19
  • 1
    Check this out: dba.stackexchange.com/questions/335749/…
    – mustaccio
    Feb 13 at 16:34
  • 2
    Turn on track_io_timing on both instances, then repeat the plans on both instances.
    – jjanes
    Feb 13 at 17:43
  • 1
    It's odd that neither the number of rows, nor their width is identical. Makes me doubt your comparison. Feb 14 at 1:58

1 Answer 1

1

You added insightful findings about dropped columns later. That might explain some of the performance difference. But normally, 99 % of that would be covered by VACUUM FULL, without having to create a new table (or database for that matter).

Dropping a column is a very fast operation in Postgres. The entry in the system catalog pg_attribute is not removed, just marked with attisdropped. (Depending objects are dropped, like indexes or FK references.) This avoids a time-consuming table-rewrite, renumbering attributes, etc., so it can be very fast. Physical storage of table rows is unchanged, the columns is invisible for future queries, but still occupies space. See:

VACUUM FULL (or CLUSTER, or community tools like pg_squeeze or pg_repack) physically rewrite the table in pristine condition, removing all bloat. Zombi values from dropped columns are replaced with null in the process, which occupies a single bit in the null bitmap. (One might argue that VACUUM FULL should clean out dropped columns. But it's just not implemented.) Normally, that covers 99 % of any possibly impact zombi columns might have.

There are corner cases. Dropping columns routinely could pile up zombis. (And we all know from the movies how that can become a threat where a few zombis are harmless. So avoid that.) But you reported two dropped columns. Should barely even matter after VACUUM FULL.

The worst case imaginable would be a table of 7 boolean columns. The null bit map would be "for free". See:

Two dropped columns would bring the number up to 9 and force allocation of 8 bytes for every row. Storage size without zombis: 4 + 24 + 8 = 36 bytes, Storage size with zombis: 4 + 24 + 8 + 8 = 44 bytes. Even that, while making a notable difference, wouldn't come close to explaining the 4-5 fold speedup you report.

I am puzzled how rewriting the table could have such a big impact where VACUUM FULL did not. Are you sure you did run VACUUM FULL to completion in your tests?


Aside, the observed variation in the estimated row width can be caused by variable-size columns (like varchar or jsonb, ...). Column statistics are built by ANALYZE (or autovacuum) based on a random sample and can show fluctuation in this case.

1
  • Are zombie columns the reason for poor performance? we don't know. We just know if I create new table from select, performance is good, but I can wipe another problem that the original table had. Yes, I launch vacuum full in my tests. If you have more tests, we can investigate this futher.
    – Mapashito
    Feb 23 at 10:47

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.