Обсуждение: slow "select count(*) from information_schema.tables;" in some cases

Поиск
Список
Период
Сортировка

slow "select count(*) from information_schema.tables;" in some cases

От
Lars Aksel Opsahl
Дата:
Hi

Sometimes simple sql's like this takes a very long time  "select count(*) from information_schema.tables;"

Other sql's not including system tables may work ok but login also takes a very long time. 

The CPU load on the server is around 25%. There is no iowait.


This happens typically when we are running many functions in parallel creating many temp tables and unlogged tables I think.

Here is a slow one:  

https://explain.depesz.com/s/tUt5 


and here is fast one :

https://explain.depesz.com/s/yYG4 


Here are my settings (the server has around 256 GB og memory) :

max_connections = 500

work_mem = 20MB

effective_cache_size = 96GB 

effective_io_concurrency = 256 

shared_buffers = 96GB

temp_buffers = 80MB

Any hints ?


Thanks .


Lars

Re: slow "select count(*) from information_schema.tables;" in some cases

От
Justin Pryzby
Дата:
On Mon, Feb 07, 2022 at 04:56:35PM +0000, Lars Aksel Opsahl wrote:
> Sometimes simple sql's like this takes a very long time  "select count(*) from information_schema.tables;"
> 
> Other sql's not including system tables may work ok but login also takes a very long time.
> 
> The CPU load on the server is around 25%. There is no iowait.
> 
> This happens typically when we are running many functions in parallel creating many temp tables and unlogged tables I
think.
> 
> Here is a slow one:
> https://explain.depesz.com/s/tUt5
> 
> and here is fast one :
> https://explain.depesz.com/s/yYG4

The only difference is that this is sometimes many times slower.

 Finalize Aggregate  (cost=42021.15..42021.16 rows=1 width=8) (actual time=50602.755..117201.768 rows=1 loops=1)
   ->  Gather  (cost=42020.94..42021.15 rows=2 width=8) (actual time=130.527..117201.754 rows=3 loops=1)
         Workers Planned: 2
         Workers Launched: 2

> Here are my settings (the server has around 256 GB og memory) :

What version of postgres ?  What OS/version ?
https://wiki.postgresql.org/wiki/Slow_Query_Questions

Are there any server logs around that time ?
Or session logs for the slow query ?

Is it because the table creation is locking (rows of) various system catalogs ?
I'm not sure if it'd be a single, long delay that you could see easily with
log_lock_waits, or a large number of small delays, maybe depending on whether
your table creation is done within a transaction.

-- 
Justin



Re: slow "select count(*) from information_schema.tables;" in some cases

От
Lars Aksel Opsahl
Дата:

>>

>> Here is a slow one:

>> https://explain.depesz.com/s/tUt5

>>

>> and here is fast one :

>> https://explain.depesz.com/s/yYG4

>

>The only difference is that this is sometimes many times slower.

>

> Finalize Aggregate  (cost=42021.15..42021.16 rows=1 width=8) (actual time=50602.755..117201.768 rows=1 loops=1)

>   ->  Gather  (cost=42020.94..42021.15 rows=2 width=8) (actual time=130.527..117201.754 rows=3 loops=1)

>         Workers Planned: 2

>         Workers Launched: 2

>

>> Here are my settings (the server has around 256 GB og memory) :

>


Hi


Here is some more info.


>What version of postgres ?  What OS/version ?


psql (14.1, server 12.6 (Ubuntu 12.6-0ubuntu0.20.04.1))

>https://wiki.postgresql.org/wiki/Slow_Query_Questions

>

>Are there any server logs around that time ?


Yes but nothing in the logs that I could find.


>Or session logs for the slow query ?

>

>Is it because the table creation is locking (rows of) various system catalogs ?

>I'm not sure if it'd be a single, long delay that you could see easily with

>log_lock_waits, or a large number of small delays, maybe depending on whether

>your table creation is done within a transaction.


Added log_lock_waits but could not  anything new in the logs


SHOW deadlock_timeout ;

 deadlock_timeout 

------------------

 1s

 SHOW log_lock_waits;

 log_lock_waits 

----------------

 on

(1 row)


In the logs I only things like this

LOG:  duration: 71841.233 ms  statement: CREATE UNLOGGED TABLE IF NOT EXISTS tmp_klimagass.styredata_tidligbygg_159298.....


LOG:  duration: 12645.127 ms  statement: GRANT SELECT ON TABLE tmp_klimagass.vaerdata_159296 TO org_mojo2_sl_read_role;

LOG:  duration: 15783.611 ms  statement: EXPLAIN ANALYZE select count(*)

        from information_schema.tables;

LOG:  duration: 35594.903 ms  statement: EXPLAIN ANALYZE select count(*)

Can not find anything here either


select relation::regclass, * from pg_locks where not granted; 

 relation | locktype | database | relation | page | tuple | virtualxid | transactionid | classid | objid | objsubid | virtualtransaction | pid | mode | granted | fastpath 

----------+----------+----------+----------+------+-------+------------+---------------+---------+-------+----------+--------------------+-----+------+---------+----------

(0 rows)


Time: 55.270 ms


>

>--

>Justin


Thanks

Lars

Re: slow "select count(*) from information_schema.tables;" in some cases

От
Vijaykumar Jain
Дата:


On Mon, Feb 7, 2022, 10:26 PM Lars Aksel Opsahl <Lars.Opsahl@nibio.no> wrote:
Hi

Sometimes simple sql's like this takes a very long time  "select count(*) from information_schema.tables;"

Other sql's not including system tables may work ok but login also takes a very long time. 

The CPU load on the server is around 25%. There is no iowait.


This happens typically when we are running many functions in parallel creating many temp tables and unlogged tables I think.

Here is a slow one:  

https://explain.depesz.com/s/tUt5 


and here is fast one :

https://explain.depesz.com/s/yYG4 


Here are my settings (the server has around 256 GB og memory) :

max_connections = 500

work_mem = 20MB

effective_cache_size = 96GB 

effective_io_concurrency = 256 

shared_buffers = 96GB

temp_buffers = 80MB

Any hints ?


Thanks .


Lars


Can you share the output of the below query?

From the past threads I have learnt that too many templates objects may add to bloat of system catalogs and may in start resulting in impacting performance.
Make a note especially  around

pg_attribute
pg_depends
and check for bloat, if required, vacuum full? these objects to speed up.



SELECT relname, pg_size_pretty(pg_relation_size(C.oid)) FROM pg_class C LEFT JOIN pg_namespace N ON (N.oid = C.relnamespace) WHERE nspname = 'pg_catalog' ORDER BY 2 DESC LIMIT 20; can you show the output of this query

Re: slow "select count(*) from information_schema.tables;" in some cases

От
Lars Aksel Opsahl
Дата:

>Vijaykumar Jain <vijaykumarjain.github@gmail.com>

>Mon 2/7/2022 6:49 PM

>

>On Mon, Feb 7, 2022, 10:26 PM Lars Aksel Opsahl <Lars.Opsahl@nibio.no> wrote:

>Hi

>


Hi


>Can you share the output of the below query?

>

>From the past threads I have learnt that too many templates objects may add to bloat of system catalogs and may in start resulting in impacting performance.

>Make a note especially  around

>

>pg_attribute

>pg_depends

>and check for bloat, if required, vacuum full? these objects to speed up.

>

>

>

>SELECT relname, pg_size_pretty(pg_relation_size(C.oid)) FROM pg_class C LEFT JOIN pg_namespace N ON (N.oid = C.relnamespace) WHERE nspname = 'pg_catalog' ORDER BY 2 DESC LIMIT 20; can you show the output of this query



SELECT relname, pg_size_pretty(pg_relation_size(C.oid)) FROM pg_class C LEFT JOIN pg_namespace N ON (N.oid = C.relnamespace) WHERE nspname = 'pg_catalog' ORDER BY 2 DESC LIMIT 20;

            relname             | pg_size_pretty 

--------------------------------+----------------

 pg_attrdef_oid_index           | 9744 kB

 pg_attrdef_adrelid_adnum_index | 9712 kB

 pg_type_typname_nsp_index      | 87 MB

 pg_sequence_seqrelid_index     | 8224 kB

 pg_foreign_table_relid_index   | 8192 bytes

 pg_enum_typid_sortorder_index  | 8192 bytes

 pg_largeobject_metadata        | 8192 bytes

 pg_event_trigger_oid_index     | 8192 bytes

 pg_extension                   | 8192 bytes

 pg_event_trigger_evtname_index | 8192 bytes

 pg_am                          | 8192 bytes

 pg_foreign_data_wrapper        | 8192 bytes

 pg_foreign_server_name_index   | 8192 bytes

 pg_enum_typid_label_index      | 8192 bytes

 pg_default_acl                 | 8192 bytes

 pg_foreign_server_oid_index    | 8192 bytes

 pg_db_role_setting             | 8192 bytes

 pg_database                    | 8192 bytes

 pg_enum_oid_index              | 8192 bytes

 pg_language                    | 8192 bytes

(20 rows)


Time: 22.354 ms


VACUUM full pg_attribute;

40P01: deadlock detected

VACUUM full pg_depends;

40P01: deadlock detected


I have to test those later


This works ok

VACUUM pg_attribute;

VACUUM pg_depends;


VACUUM full pg_attrdef;

VACUUM full pg_type ;

VACUUM full pg_sequence;

VACUUM full pg_type;


SELECT relname, pg_size_pretty(pg_relation_size(C.oid)) FROM pg_class C LEFT JOIN pg_namespace N ON (N.oid = C.relnamespace) WHERE nspname = 'pg_catalog' ORDER BY 2 DESC LIMIT 20;

               relname                | pg_size_pretty 

--------------------------------------+----------------

 pg_type_oid_index                    | 960 kB

 pg_language                          | 8192 bytes

 pg_enum_typid_label_index            | 8192 bytes

 pg_pltemplate                        | 8192 bytes

 pg_event_trigger_oid_index           | 8192 bytes

 pg_foreign_server_oid_index          | 8192 bytes

 pg_foreign_server_name_index         | 8192 bytes

 pg_enum_oid_index                    | 8192 bytes

 pg_largeobject_metadata              | 8192 bytes

 pg_foreign_table_relid_index         | 8192 bytes

 pg_am                                | 8192 bytes

 pg_database                          | 8192 bytes

 pg_event_trigger_evtname_index       | 8192 bytes

 pg_extension                         | 8192 bytes

 pg_partitioned_table_partrelid_index | 8192 bytes

 pg_enum_typid_sortorder_index        | 8192 bytes

 pg_db_role_setting                   | 8192 bytes

 pg_default_acl                       | 8192 bytes

 pg_foreign_data_wrapper              | 8192 bytes

 pg_publication_oid_index             | 8192 bytes

Still slow.


Lars

Re: slow "select count(*) from information_schema.tables;" in some cases

От
Tom Lane
Дата:
Lars Aksel Opsahl <Lars.Opsahl@nibio.no> writes:
>> SELECT relname, pg_size_pretty(pg_relation_size(C.oid)) FROM pg_class C LEFT JOIN pg_namespace N ON (N.oid =
C.relnamespace)WHERE nspname = 'pg_catalog' ORDER BY 2 DESC LIMIT 20; can you show the output of this query 

"ORDER BY 2" is giving you a textual sort of the sizes, which is entirely
unhelpful.  Try

SELECT relname, pg_size_pretty(pg_relation_size(C.oid)) FROM pg_class C LEFT JOIN pg_namespace N ON (N.oid =
C.relnamespace)WHERE nspname = 'pg_catalog' ORDER BY pg_relation_size(C.oid) DESC LIMIT 20; 

            regards, tom lane



Re: slow "select count(*) from information_schema.tables;" in some cases

От
Lars Aksel Opsahl
Дата:


>From: Tom Lane <tgl@sss.pgh.pa.us>

>Sent: Monday, February 7, 2022 8:02 PM

>To: Lars Aksel Opsahl <Lars.Opsahl@nibio.no>

>Cc: Vijaykumar Jain <vijaykumarjain.github@gmail.com>; Pgsql Performance <pgsql-performance@lists.postgresql.org>

>Subject: Re: slow "select count(*) from information_schema.tables;" in some cases

> 

>Lars Aksel Opsahl <Lars.Opsahl@nibio.no> writes:

>>> SELECT relname, pg_size_pretty(pg_relation_size(C.oid)) FROM pg_class C LEFT JOIN pg_namespace N ON (N.oid = C.relnamespace) WHERE nspname = 'pg_catalog' ORDER BY 2 DESC LIMIT 20; can you show the output of this query

>

>"ORDER BY 2" is giving you a textual sort of the sizes, which is entirely

>unhelpful.  Try

>

>SELECT relname, pg_size_pretty(pg_relation_size(C.oid)) FROM pg_class C LEFT JOIN pg_namespace N ON (N.oid = C.relnamespace) WHERE nspname = 'pg_catalog' ORDER BY pg_relation_size(C.oid) DESC LIMIT 20;

>

>                        regards, tom lane

>


Hi

Then pg_attribute show up yes. I have to vacuum full later when server is free.


SELECT relname, pg_size_pretty(pg_relation_size(C.oid)) FROM pg_class C LEFT JOIN pg_namespace N ON (N.oid = C.relnamespace) WHERE nspname = 'pg_catalog' ORDER BY pg_relation_size(C.oid) DESC LIMIT 20;

              relname              | pg_size_pretty 

-----------------------------------+----------------

 pg_largeobject                    | 17 GB

 pg_attribute                      | 1452 MB

 pg_statistic                      | 1103 MB

 pg_class                          | 364 MB

 pg_attribute_relid_attnam_index   | 307 MB

 pg_depend                         | 285 MB

 pg_largeobject_loid_pn_index      | 279 MB

 pg_attribute_relid_attnum_index   | 230 MB

 pg_depend_reference_index         | 207 MB

 pg_depend_depender_index          | 198 MB

 pg_class_relname_nsp_index        | 133 MB

 pg_index                          | 111 MB

 pg_statistic_relid_att_inh_index  | 101 MB

 pg_class_oid_index                | 52 MB

 pg_class_tblspc_relfilenode_index | 46 MB

 pg_shdepend                       | 38 MB

 pg_shdepend_depender_index        | 25 MB

 pg_index_indexrelid_index         | 24 MB

 pg_shdepend_reference_index       | 21 MB

 pg_index_indrelid_index           | 18 MB

(20 rows)


Thanks


Re: slow "select count(*) from information_schema.tables;" in some cases

От
Imre Samu
Дата:

Hi Lars,


> psql (14.1, server 12.6 (Ubuntu 12.6-0ubuntu0.20.04.1))

Maybe you can upgrade to 12.9 ( from 12.6 )     ( https://www.postgresql.org/docs/release/12.9/ )
And the next minor release = pg 12.10 is expected on February 10th, 2022 https://www.postgresql.org/developer/roadmap/ 

As I see - only a minor fix exists for "system columns":  "Don't ignore system columns when estimating the number of groups using extended statistics (Tomas Vondra)"  in 12.7

I have similar experiences with the system tables - vacuuming is extreme important
in my case -  I am calling "vacuum" in every ETL job - cleaning my system tables. 

select
  schemaname
  ,relname
  ,n_tup_ins
  ,n_tup_upd
  ,n_tup_del
  ,n_tup_hot_upd
  ,n_live_tup
  ,n_dead_tup
from pg_stat_all_tables
where n_dead_tup > 0 and schemaname='pg_catalog'
;

Regards,
 Imre


Lars Aksel Opsahl <Lars.Opsahl@nibio.no> ezt írta (időpont: 2022. febr. 7., H, 18:40):

>>

>> Here is a slow one:

>> https://explain.depesz.com/s/tUt5

>>

>> and here is fast one :

>> https://explain.depesz.com/s/yYG4

>

>The only difference is that this is sometimes many times slower.

>

> Finalize Aggregate  (cost=42021.15..42021.16 rows=1 width=8) (actual time=50602.755..117201.768 rows=1 loops=1)

>   ->  Gather  (cost=42020.94..42021.15 rows=2 width=8) (actual time=130.527..117201.754 rows=3 loops=1)

>         Workers Planned: 2

>         Workers Launched: 2

>

>> Here are my settings (the server has around 256 GB og memory) :

>


Hi


Here is some more info.


>What version of postgres ?  What OS/version ?


psql (14.1, server 12.6 (Ubuntu 12.6-0ubuntu0.20.04.1))

>https://wiki.postgresql.org/wiki/Slow_Query_Questions

>

>Are there any server logs around that time ?


Yes but nothing in the logs that I could find.


>Or session logs for the slow query ?

>

>Is it because the table creation is locking (rows of) various system catalogs ?

>I'm not sure if it'd be a single, long delay that you could see easily with

>log_lock_waits, or a large number of small delays, maybe depending on whether

>your table creation is done within a transaction.


Added log_lock_waits but could not  anything new in the logs


SHOW deadlock_timeout ;

 deadlock_timeout 

------------------

 1s

 SHOW log_lock_waits;

 log_lock_waits 

----------------

 on

(1 row)


In the logs I only things like this

LOG:  duration: 71841.233 ms  statement: CREATE UNLOGGED TABLE IF NOT EXISTS tmp_klimagass.styredata_tidligbygg_159298.....


LOG:  duration: 12645.127 ms  statement: GRANT SELECT ON TABLE tmp_klimagass.vaerdata_159296 TO org_mojo2_sl_read_role;

LOG:  duration: 15783.611 ms  statement: EXPLAIN ANALYZE select count(*)

        from information_schema.tables;

LOG:  duration: 35594.903 ms  statement: EXPLAIN ANALYZE select count(*)

Can not find anything here either


select relation::regclass, * from pg_locks where not granted; 

 relation | locktype | database | relation | page | tuple | virtualxid | transactionid | classid | objid | objsubid | virtualtransaction | pid | mode | granted | fastpath 

----------+----------+----------+----------+------+-------+------------+---------------+---------+-------+----------+--------------------+-----+------+---------+----------

(0 rows)


Time: 55.270 ms


>

>--

>Justin


Thanks

Lars

Re: slow "select count(*) from information_schema.tables;" in some cases

От
Lars Aksel Opsahl
Дата:

Hi



>From: Imre Samu <pella.samu@gmail.com>
>Sent: Monday, February 7, 2022 8:51 PM
>Maybe you can upgrade to 12.9 ( from 12.6 )     ( https://www.postgresql.org/docs/release/12.9/ )

>And the next minor release = pg 12.10 is expected on February 10th, 2022 https://www.postgresql.org/developer/roadmap/ 

>As I see - only a minor fix exists for "system columns":  "Don't ignore system columns when estimating the number of groups using extended statistics (Tomas Vondra)"  in 12.7

>

>I have similar experiences with the system tables - vacuuming is extreme important

>in my case -  I am calling "vacuum" in every ETL job - cleaning my system tables. 

>


Thanks we may test upgrade later seems like the problem here was related to both vacuum and set parallel_workers to 0 in this case, see mail for more info.


SELECT relname, pg_size_pretty(pg_relation_size(C.oid)) FROM pg_class C LEFT JOIN pg_namespace N ON (N.oid = C.relnamespace) WHERE nspname = 'pg_catalog' ORDER BY pg_relation_size(C.oid) DESC LIMIT 20;

              relname              | pg_size_pretty 

-----------------------------------+----------------

 pg_largeobject                    | 17 GB

 pg_attribute                      | 1452 MB

 pg_statistic                      | 1103 MB

 pg_class                          | 364 MB

 pg_attribute_relid_attnam_index   | 307 MB

 pg_depend                         | 285 MB

 pg_largeobject_loid_pn_index      | 279 MB

 pg_attribute_relid_attnum_index   | 230 MB

 pg_depend_reference_index         | 207 MB

 pg_depend_depender_index          | 198 MB

 pg_class_relname_nsp_index        | 133 MB

 pg_index                          | 111 MB

 pg_statistic_relid_att_inh_index  | 101 MB

 pg_class_oid_index                | 52 MB

 pg_class_tblspc_relfilenode_index | 46 MB

 pg_shdepend                       | 38 MB

 pg_shdepend_depender_index        | 25 MB

 pg_index_indexrelid_index         | 24 MB

 pg_shdepend_reference_index       | 21 MB

 pg_index_indrelid_index           | 18 MB

(20 rows)


select

  schemaname

  ,relname

  ,n_tup_ins

  ,n_tup_upd

  ,n_tup_del

  ,n_tup_hot_upd

  ,n_live_tup

  ,n_dead_tup

from pg_stat_all_tables

where n_dead_tup > 0 and schemaname='pg_catalog'

;

 schemaname |      relname       | n_tup_ins | n_tup_upd | n_tup_del | n_tup_hot_upd | n_live_tup | n_dead_tup 

------------+--------------------+-----------+-----------+-----------+---------------+------------+------------

 pg_catalog | pg_default_acl     |         6 |         2 |         1 |             2 |          5 |          3

 pg_catalog | pg_shdepend        |  10994319 |        53 |  10975090 |             0 |      32982 |       1711

 pg_catalog | pg_type            |  24820549 |      4558 |  24610078 |           300 |      41619 |       5492

 pg_catalog | pg_attribute       | 183016129 |  13549029 | 181178505 |       8326103 |     418492 |      46415

 pg_catalog | pg_proc            |      1406 |      1340 |      1187 |          1122 |       6551 |       1351

 pg_catalog | pg_class           |  30278004 |   8510013 |  30021392 |       5917849 |      50569 |       6193

 pg_catalog | pg_authid          |        50 |         7 |        10 |             7 |        887 |         30

 pg_catalog | pg_auth_members    |        39 |         0 |         1 |             0 |         38 |          2

 pg_catalog | pg_sequence        |   5101683 |   5100683 |   5087311 |       5045867 |       3250 |        507

 pg_catalog | pg_attrdef         |   6859893 |         0 |   6683508 |             0 |       3973 |        256

 pg_catalog | pg_constraint      |     56521 |         4 |     42635 |             0 |       9317 |       1782

 pg_catalog | pg_depend          |  89540444 |         8 |  88833727 |             0 |     211747 |      21601

 pg_catalog | pg_description     |      3561 |      4478 |      3528 |          3745 |       8259 |        967

 pg_catalog | pg_index           |  12360100 |    262429 |  12220917 |        258746 |      40690 |       1003

 pg_catalog | pg_namespace       |       210 |       122 |        14 |           118 |        841 |        145

 pg_catalog | pg_rewrite         |       659 |        83 |       573 |            62 |       1757 |        161

 pg_catalog | pg_statistic       |   2342496 |  25301064 |   2317015 |       2452817 |     732310 |      48825

 pg_catalog | pg_trigger         |      2495 |         0 |      2085 |             0 |       7367 |        697

 pg_catalog | pg_db_role_setting |         0 |         1 |         0 |             1 |          0 |          1

(19 rows)


First I tested vacuum only on the big tables 


 VACUUM full pg_largeobject;

 VACUUM full pg_class ;

 VACUUM full pg_attribute;

 VACUUM full pg_depend ;

 VACUUM full pg_depend_reference_index ;

 VACUUM full pg_index;


But then select count(*) from information_schema.tables started to slow down again.


--select format('vacuum FULL verbose %I.%I;', n.nspname::varchar, t.relname::varchar) FROM pg_class t JOIN pg_namespace n ON n.oid = t.relnamespace WHERE t.relkind = 'r' and n.nspname::varchar = 'pg_catalog' order by 1


Then I did vacuum all tables in pg_catalog and then "select count(*) from information_schema.tables;" is seems to be fast while running the background job.


SELECT relname, pg_size_pretty(pg_relation_size(C.oid)) FROM pg_class C LEFT JOIN pg_namespace N ON (N.oid = C.relnamespace) WHERE nspname = 'pg_catalog' ORDER BY pg_relation_size(C.oid) DESC LIMIT 20;

             relname              | pg_size_pretty 

----------------------------------+----------------

 pg_largeobject                   | 4624 MB

 pg_statistic                     | 76 MB

 pg_attribute                     | 61 MB

 pg_largeobject_loid_pn_index     | 42 MB

 pg_attribute_relid_attnam_index  | 13 MB

 pg_depend                        | 12 MB

 pg_class                         | 9664 kB

 pg_attribute_relid_attnum_index  | 9376 kB

 pg_type                          | 7632 kB

 pg_depend_reference_index        | 6592 kB

 pg_depend_depender_index         | 6576 kB

 pg_index                         | 4184 kB

 pg_proc                          | 3512 kB

 pg_constraint                    | 3336 kB

 pg_statistic_relid_att_inh_index | 3200 kB

 pg_class_relname_nsp_index       | 2568 kB

 pg_type_typname_nsp_index        | 2000 kB

 pg_shdepend                      | 1960 kB

 pg_attrdef                       | 1800 kB

 pg_rewrite                       | 1392 kB

(20 rows)


select                                                                                                                                                                   

  schemaname

  ,relname

  ,n_tup_ins

  ,n_tup_upd

  ,n_tup_del

  ,n_tup_hot_upd

  ,n_live_tup

  ,n_dead_tup

from pg_stat_all_tables

where n_dead_tup > 0 and schemaname='pg_catalog'

;

 schemaname |      relname       | n_tup_ins | n_tup_upd | n_tup_del | n_tup_hot_upd | n_live_tup | n_dead_tup 

------------+--------------------+-----------+-----------+-----------+---------------+------------+------------

 pg_catalog | pg_default_acl     |         6 |         2 |         1 |             2 |         17 |         10

 pg_catalog | pg_shdepend        |  10995081 |        53 |  10975244 |             0 |      33155 |       2296

 pg_catalog | pg_type            |  24822122 |      4558 |  24610467 |           300 |      41907 |       6773

 pg_catalog | pg_attribute       | 183035424 |  13549029 | 181183256 |       8326103 |     424171 |      13615

 pg_catalog | pg_proc            |      1406 |      1340 |      1187 |          1122 |       6551 |       1351

 pg_catalog | pg_class           |  30278894 |   8510613 |  30021642 |       5918109 |      50712 |       1169

 pg_catalog | pg_authid          |        50 |         7 |        10 |             7 |        887 |         30

 pg_catalog | pg_auth_members    |        39 |         0 |         1 |             0 |        860 |          2

 pg_catalog | pg_database        |         0 |         0 |         0 |             0 |          6 |          4

 pg_catalog | pg_sequence        |   5101683 |   5100683 |   5087311 |       5045867 |       3250 |        507

 pg_catalog | pg_shdescription   |         0 |         0 |         0 |             0 |         11 |          8

 pg_catalog | pg_attrdef         |   6859893 |         0 |   6683508 |             0 |       3973 |        256

 pg_catalog | pg_constraint      |     56521 |         4 |     42635 |             0 |       9317 |       1782

 pg_catalog | pg_depend          |  89542906 |         8 |  88834333 |             0 |     212177 |       2024

 pg_catalog | pg_description     |      3561 |      4478 |      3528 |          3745 |       8259 |        967

 pg_catalog | pg_index           |  12360169 |    262429 |  12220954 |        258746 |      23660 |         69

 pg_catalog | pg_namespace       |       210 |       122 |        14 |           118 |        841 |        146

 pg_catalog | pg_operator        |         0 |         0 |         0 |             0 |        840 |         20

 pg_catalog | pg_rewrite         |       659 |        83 |       573 |            62 |       1757 |        161

 pg_catalog | pg_statistic       |   2346816 |  25301535 |   2317159 |       2453015 |     144622 |        475

 pg_catalog | pg_trigger         |      2495 |         0 |      2085 |             0 |       7367 |        697

 pg_catalog | pg_db_role_setting |         0 |         1 |         0 |             1 |          4 |          4

 pg_catalog | pg_extension       |         0 |         0 |         0 |             0 |         10 |          6

 pg_catalog | pg_init_privs      |         0 |         0 |         0 |             0 |        180 |          1

(24 rows)


And that solved the simple count sql.


BUT "psql -h dbhost -p 5432 -U postgres dbname" login is still becomes slow after a while when running code that creates a lot of unlogged tables in 16 threads.


When I kill the test job it is instantly fast again


What seems to take time was this call triggered by psql (I could not find anything find else related for instance related to this locks)


EXPLAIN ANALYZE SELECT pg_catalog.quote_ident(c.relname) FROM pg_catalog.pg_class c WHERE c.relkind IN ('r', 'S', 'v', 'm', 'f', 'p') AND substring(pg_catalog.quote_ident(c.relname),1,6)='pg_sta' AND pg_catalog.pg_table_is_visible(c.oid)

UNION

SELECT pg_catalog.quote_ident(n.nspname) || '.' FROM pg_catalog.pg_namespace n WHERE substring(pg_catalog.quote_ident(n.nspname) || '.',1,6)='pg_sta' AND (SELECT pg_catalog.count(*) FROM pg_catalog.pg_namespace WHERE substring(pg_catalog.quote_ident(nspname) || '.',1,6) = substring('pg_sta',1,pg_catalog.length(pg_catalog.quote_ident(nspname))+1)) > 1

UNION

SELECT pg_catalog.quote_ident(n.nspname) || '.' || pg_catalog.quote_ident(c.relname) FROM pg_catalog.pg_class c, pg_catalog.pg_namespace n WHERE c.relnamespace = n.oid AND c.relkind IN ('r', 'S', 'v', 'm', 'f', 'p') AND substring(pg_catalog.quote_ident(n.nspname) || '.' || pg_catalog.quote_ident(c.relname),1,6)='pg_sta' AND substring(pg_catalog.quote_ident(n.nspname) || '.',1,6) = substring('pg_sta',1,pg_catalog.length(pg_catalog.quote_ident(n.nspname))+1) AND (SELECT pg_catalog.count(*) FROM pg_catalog.pg_namespace WHERE substring(pg_catalog.quote_ident(nspname) || '.',1,6) = substring('pg_sta',1,pg_catalog.length(pg_catalog.quote_ident(nspname))+1)) = 1

LIMIT 1000


Here is slow one https://explain.depesz.com/s/x2Vf the app is running 


After the killing the application is fast https://explain.depesz.com/s/h4fK


We also tried to change the code to do this in 2 steps.

- First create table

- Then insert data into table


But that does not help on login either the time vary from 30 secs to 75 sec.

https://explain.depesz.com/s/4SXl


There is no iowait the server the CPU load is 25%, the problem seems to be related to parallel_workers


max_parallel_workers_per_gather 

---------------------------------

 2

 max_parallel_workers 

----------------------

 8

 max_worker_processes 

----------------------

 8


So if we change max_parallel_workers_per_gather = 0


Then https://explain.depesz.com/s/kMEm query is fast.


Thanks for help everybody seems like we have to dig into the parallel_workers world.


(have to wait to test that until we can restart postgres)


Lars