Thread: ogr2ogr slow sql when checking system tables for column info and so on.

CREATE SCHEMA test_pg_metadata;                                  

Hi,

On Fri, Oct 21, 2022 at 09:19:58AM +0000, Lars Aksel Opsahl wrote:
>
> The main problem is that for instance ogr2ogr is using more time to get system info about tables than doing the
actualjob.
 
>
> The time pick up postgresql meta info takes between 30 and 60 seconds and sometimes hours if we have not done vacuum
analyzerecenlty.
 
> Then actual spatial jobs takes less than 10 seconds.
>
> Before I run ogr2ogr I do vacuum analyze
>
>  schemaname |    relname     | n_live_tup | n_dead_tup |        last_autovacuum
> ------------+----------------+------------+------------+-------------------------------
>  pg_catalog | pg_class       |     215296 |       4365 | 2022-10-18 10:24:05.745915+02
>  pg_catalog | pg_attribute   |    1479648 |      18864 | 2022-10-18 12:36:52.820133+02
>  pg_catalog | pg_type        |     200777 |       2318 | 2022-10-18 06:33:58.598257+02
>  pg_catalog | pg_constraint  |      10199 |        104 | 2022-10-20 15:10:57.894674+02
>  pg_catalog | pg_namespace   |        860 |          1 | [NULL]
>  pg_catalog | pg_description |       9119 |          0 | 2022-05-06 01:59:58.664618+02
> (6 rows)
>
> VACUUM ANALYZE pg_catalog.pg_class;
> VACUUM ANALYZE pg_catalog.pg_attribute;
> VACUUM ANALYZE pg_catalog.pg_namespace;
> VACUUM ANALYZE pg_catalog.pg_type;
> VACUUM ANALYZE pg_catalog.pg_constraint;
> VACUUM ANALYZE pg_catalog.pg_description;
>
> After running, we have this values
>
> schemaname |    relname     | n_live_tup | n_dead_tup |        last_autovacuum
> ------------+----------------+------------+------------+-------------------------------
>  pg_catalog | pg_class       |     221739 |        464 | 2022-10-18 10:24:05.745915+02
>  pg_catalog | pg_namespace   |        860 |          2 |
>  pg_catalog | pg_attribute   |    1464900 |       1672 | 2022-10-18 12:36:52.820133+02
>  pg_catalog | pg_constraint  |      10200 |          8 | 2022-10-20 15:10:57.894674+02
>  pg_catalog | pg_type        |     204936 |         93 | 2022-10-18 06:33:58.598257+02
>  pg_catalog | pg_description |       9119 |          0 | 2022-05-06 01:59:58.664618+02
> (6 rows)
>
> Here https://explain.depesz.com/s/oU19#stats the sql generated by ogr2ogr that takes 33 seconds in this sample
> [...]
> ->  Seq Scan on pg_attribute a  (rows=1464751) (actual time=0.028..17740.663
> [...]
> Then we take copy of the pg_catalog tables involved.
>
> Here https://explain.depesz.com/s/NEwB#source is the trace when using the same sql as from ogr2ogr but using the
tablesin test_pg_metadata and then it runs in 5 seconds.
 
> [...]
> ->  Seq Scan on pg_attribute a  (rows=1452385) (actual time=0.006..156.392
>
> I do not understand way it's so much slower to use the tables in  pg_catalog than in test_pg_metadata tables because
theyhave the same content.
 

In both case you have a sequential scan over the pg_attribute table, but for
pg_catalog it takes 17 seconds to retrieve the 1.4M rows, and in the new table
it takes 156 ms.

It looks like you catalog is heavily bloated, which is the cause of the
slowdown.

You could do a VACUUM FULL of the tables in pg_catalog but it would only be a
short term fix as it's likely that your catalog will get bloated again.  Do you
rely a lot on temporary tables?  If yes it can easily lead to this kind of side
effect, and you should modify you code to perform manual vacuum of catalogs
tables very often, or add a dedicated high frequency task for running similar
vacuum and keep the bloat under control.

---

>From: Julien Rouhaud <rjuju123@gmail.com>

Hi,

On Fri, Oct 21, 2022 at 10:30:27AM +0000, Lars Aksel Opsahl wrote:
>
> >
> >In both case you have a sequential scan over the pg_attribute table, but for
> >pg_catalog it takes 17 seconds to retrieve the 1.4M rows, and in the new table
> >it takes 156 ms.
> >
> >It looks like you catalog is heavily bloated, which is the cause of the
> >slowdown.
> >
> >You could do a VACUUM FULL of the tables in pg_catalog but it would only be a
> >short term fix as it's likely that your catalog will get bloated again.  Do you
> >rely a lot on temporary tables?  If yes it can easily lead to this kind of side
> >effect, and you should modify you code to perform manual vacuum of catalogs
> >tables very often, or add a dedicated high frequency task for running similar
> >vacuum and keep the bloat under control.
>
> Yes we use a lot of temp tables sometimes .

What do you mean by sometimes?  If you only have non frequent or specialized
jobs the creates a lot of temp tables, you just need to modify them to issue
some VACUUM (not VACUUM FULL) at the end, or regularly if you creates millions
of tables in a single job.

> With "VACUUM FULL ANALYZE " we got the same time as from the created tables
> https://explain.depesz.com/s/Yxy9 so that works.
>
> OK then we start up by trigger a 'VACUUM FULL ANALYZE ' for all the tables in
> th pg_catalog because this seems to be only thing that is working for now.

Just to be clear the VACUUM FULL is only needed to shrink the tables which were
likely multiple GB each.  If you do simple VACUUM frequently enough, you won't
have too much bloat in the first place and everything will just work as
intended.

You could setup some monitoring on the size of the catalog tables to make sure
that you run those maintenance as frequently as necessary.

> I assume that adding more indexes on the tables in pg_catalog to avoid tables
> scans are not  that easy.

Indeed, that's not a supported operation.

---

>From: Julien Rouhaud <rjuju123@gmail.com>Sent: Friday, October 21, 2022 12:41 PMTo: Lars Aksel Opsahl <Lars.Opsahl@nibio.no>Cc: pgsql-performance@lists.postgresql.org <pgsql-performance@lists.postgresql.org>Subject: Re: ogr2ogr slow sql when checking system tables for column info and so on. >